Sorry, forgot to attach the log:
----------------------------------------
PROCESSING INTERNAL STATE: -- StageOut --
----------------------------------------
2012-09-11T17:49:48.478-04:00 DEBUG processing.StateMachine
[pool-1-thread-1,processInternalState:115] Processing resource
d69fb7c0-fc45-11e1-93da-f931d11c3d83 in internal state StageOut
2012-09-11T17:49:48.478-04:00 DEBUG handler.InternalStateHandler
[pool-1-thread-1,processInternalState:44]
[resourceKey:d69fb7c0-fc45-11e1-93da-f931d11c3d83] Start processing
internal state StageOut
2012-09-11T17:49:48.484-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,setState:846] receiving request for state change to
StageOut
2012-09-11T17:49:48.484-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,setState:525] Setting new state RP value StageOut
2012-09-11T17:49:48.484-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,setState:854] State of job {
http://www.globus.org/namespaces/2008/03/gram/job}ResourceID=d69fb7c0-fc45-11e1-93da-f931d11c3d83changed
to: StageOut
2012-09-11T17:49:48.484-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,setState:862] Holding: false
2012-09-11T17:49:48.484-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,setState:896] exitCode is null
2012-09-11T17:49:48.485-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,setState:905] Notifying of job state change to topic
listeners
2012-09-11T17:49:48.549-04:00 DEBUG utils.LocalStagingHelper
[pool-1-thread-1,submitStagingRequest:72]
[resourceKey:d69fb7c0-fc45-11e1-93da-f931d11c3d83] Entering
sumbitStagingRequest()
2012-09-11T17:49:48.552-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,getStagingCredential:434] getStagingCredential() called
2012-09-11T17:49:48.552-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,getResourceDatum:209] getting resource datum gridMapFile
2012-09-11T17:49:48.554-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,getStagingCredential:453] staging credential endpoint:
Address: https://128.8.91.70:8443/wsrf/services/DelegationService
Reference property[0]:
<ns1:DelegationKey xmlns:ns1="
http://www.globus.org/08/2004/delegationService
">d61f6430-fc45-11e1-93da-f931d11c3d83</ns1:DelegationKey>
2012-09-11T17:49:48.554-04:00 DEBUG utils.DelegatedCredential
[pool-1-thread-1,getDelegatedCredential:98] Entering
getDelegatedCredential()
2012-09-11T17:49:48.554-04:00 DEBUG utils.DelegatedCredential
[pool-1-thread-1,getDelegatedCredential:112] checking for existing
credential listener
2012-09-11T17:49:48.555-04:00 DEBUG utils.DelegatedCredential
[pool-1-thread-1,getDelegationKey:605] Pulled out DelegationKey:
d61f6430-fc45-11e1-93da-f931d11c3d83
2012-09-11T17:49:48.555-04:00 DEBUG utils.DelegatedCredential
[pool-1-thread-1,getDelegatedCredential:124] reusing DelegatedCredential
object
2012-09-11T17:49:48.555-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,getStagingCredential:476] Delegated Staging Credential
Object: org.globus.exec.service.utils.DelegatedCredential@26b98a06
2012-09-11T17:49:48.555-04:00 DEBUG utils.DelegatedCredential
[pool-1-thread-1,getCredential:333] waiting to receive initial credential...
2012-09-11T17:49:48.556-04:00 DEBUG utils.DelegatedCredential
[pool-1-thread-1,getCredential:341] done waiting...
2012-09-11T17:49:48.559-04:00 DEBUG
PersistentManagedExecutableJobResource.d69fb7c0-fc45-11e1-93da-f931d11c3d83
[pool-1-thread-1,getStagingCredential:479] Using proxy with subject
/O=Grid/OU=GlobusTest/OU=
simpleCA-leucine.umiacs.umd.edu/OU=umiacs.umd.edu/CN=GT4 Adminto contact
the staging service
2012-09-11T17:49:48.580-04:00 DEBUG utils.LocalStagingHelper
[pool-1-thread-1,submitStagingRequest:91] creating RFT resource
2012-09-11T17:49:48.711-04:00 DEBUG
factory.ReliableFileTransferFactoryService [pool-1-thread-1,oldLog:168]
Registration to MDS enabled
2012-09-11T17:49:50.981-04:00 DEBUG utils.LocalInvocationHelper
[pool-1-thread-1,getServiceObject:403]
className=org.globus.transfer.reliable.service.factory.ReliableFileTransferFactoryService
handlerClass=org.globus.axis.providers.RPCProvider
2012-09-11T17:49:50.981-04:00 DEBUG utils.LocalInvocationHelper
[pool-1-thread-1,getServiceObject:416] getting the service object
2012-09-11T17:49:50.982-04:00 DEBUG utils.LocalInvocationHelper
[pool-1-thread-1,getServiceObject:422] caching service object for service
ReliableFileTransferFactoryService
2012-09-11T17:49:50.983-04:00 DEBUG utils.LocalInvocationHelper
[pool-1-thread-1,getMethod:457] caching method
ReliableFileTransferFactoryService.createReliableFileTransfer
2012-09-11T17:49:50.984-04:00 DEBUG
factory.ReliableFileTransferFactoryService [pool-1-thread-1,oldLog:168]
PerformanceLog createReliableFileTransfer() enter
2012-09-11T17:49:50.984-04:00 DEBUG
factory.ReliableFileTransferFactoryService [pool-1-thread-1,oldLog:168] Got
a transfer request
2012-09-11T17:49:51.049-04:00 DEBUG service.ReliableFileTransferHome
[pool-1-thread-1,oldLog:168] Loading the RFT home's list of resource keys
2012-09-11T17:49:51.051-04:00 DEBUG database.RFTDatabaseSetup
[pool-1-thread-1,oldLog:168] getDBConnection() enter
2012-09-11T17:49:51.051-04:00 WARN service.ReliableFileTransferHome
[pool-1-thread-1,oldLog:190] All RFT requests will fail and all GRAM jobs
that require file staging will fail.Database driver is not initialized,
Need to setup database
2012-09-11T17:49:51.052-04:00 DEBUG service.ReliableFileTransferHome
[pool-1-thread-1,oldLog:164] All RFT requests will fail and all GRAM jobs
that require file staging will fail.Database driver is not initialized,
Need to setup database
org.globus.transfer.reliable.service.database.RftDBException: Database
driver is not initialized, Need to setup database
at
org.globus.transfer.reliable.service.database.RFTDatabaseSetup.getDBConnection(RFTDatabaseSetup.java:249)
at
org.globus.transfer.reliable.service.database.ReliableFileTransferDbAdapter.getActiveRequestIds(ReliableFileTransferDbAdapter.java:917)
at
org.globus.transfer.reliable.service.ReliableFileTransferResource.getStoredResourceKeyValues(ReliableFileTransferResource.java:544)
at
org.globus.transfer.reliable.service.ReliableFileTransferHome.initialize(ReliableFileTransferHome.java:69)
at
org.globus.wsrf.jndi.BasicBeanFactory.getObjectInstance(BasicBeanFactory.java:54)
at
org.globus.wsrf.jndi.BeanFactory.getInstance(BeanFactory.java:118)
at org.globus.wsrf.jndi.BeanFactory.access$100(BeanFactory.java:40)
at
org.globus.wsrf.jndi.BeanFactory$GetInstanceAction.run(BeanFactory.java:142)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:416)
at org.globus.gsi.jaas.GlobusSubject.runAs(GlobusSubject.java:60)
at org.globus.gsi.jaas.JaasSubject.doAs(JaasSubject.java:100)
at
org.globus.wsrf.jndi.BeanFactory.getObjectInstance(BeanFactory.java:90)
at
org.apache.naming.factory.ResourceFactory.getObjectInstance(ResourceFactory.java:135)
at
javax.naming.spi.NamingManager.getObjectInstance(NamingManager.java:321)
at org.apache.naming.NamingContext.lookup(NamingContext.java:827)
at org.apache.naming.NamingContext.lookup(NamingContext.java:155)
at
org.apache.naming.SynchronizedContext.lookup(SynchronizedContext.java:69)
at org.apache.naming.NamingContext.lookup(NamingContext.java:815)
at org.apache.naming.NamingContext.lookup(NamingContext.java:155)
at
org.apache.naming.SynchronizedContext.lookup(SynchronizedContext.java:69)
at org.apache.naming.NamingContext.lookup(NamingContext.java:815)
at org.apache.naming.NamingContext.lookup(NamingContext.java:155)
at
org.apache.naming.SynchronizedContext.lookup(SynchronizedContext.java:69)
at org.apache.naming.NamingContext.lookup(NamingContext.java:815)
at org.apache.naming.NamingContext.lookup(NamingContext.java:155)
at
org.apache.naming.SynchronizedContext.lookup(SynchronizedContext.java:69)
at org.apache.naming.NamingContext.lookup(NamingContext.java:815)
at org.apache.naming.NamingContext.lookup(NamingContext.java:168)
at
org.apache.naming.SynchronizedContext.lookup(SynchronizedContext.java:81)
at javax.naming.InitialContext.lookup(InitialContext.java:409)
at
org.apache.naming.SelectorContext.lookup(SelectorContext.java:145)
at javax.naming.InitialContext.lookup(InitialContext.java:409)
at
org.globus.transfer.reliable.service.factory.ReliableFileTransferFactoryService.createReliableFileTransfer(ReliableFileTransferFactoryService.java:247)
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:616)
at
org.globus.exec.service.exec.utils.LocalInvocationHelper.callService(LocalInvocationHelper.java:140)
at
org.globus.exec.service.exec.utils.LocalStagingHelper.submitStagingRequest(LocalStagingHelper.java:95)
at
org.globus.exec.service.exec.processing.handler.StageOutStateHandler.process(StageOutStateHandler.java:79)
at
org.globus.exec.service.exec.processing.handler.InternalStateHandler.processInternalState(InternalStateHandler.java:49)
at
org.globus.exec.service.exec.processing.StateMachine.processInternalState(StateMachine.java:121)
at
org.globus.exec.service.exec.processing.StateProcessingTask.run(StateProcessingTask.java:82)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2012-09-11T17:49:51.062-04:00 DEBUG database.RFTDatabaseSetup
[pool-1-thread-1,oldLog:168] getDBConnection() enter
2012-09-11T17:49:51.062-04:00 ERROR
factory.ReliableFileTransferFactoryService [pool-1-thread-1,oldLog:175]
Unable to create RFT resource
org.globus.transfer.reliable.service.database.RftDBException: Database
driver is not initialized, Need to setup database
at
org.globus.transfer.reliable.service.database.RFTDatabaseSetup.getDBConnection(RFTDatabaseSetup.java:249)
at
org.globus.transfer.reliable.service.database.ReliableFileTransferDbAdapter.storeTransferRequest(ReliableFileTransferDbAdapter.java:204)
at
org.globus.transfer.reliable.service.ReliableFileTransferResource.<init>(ReliableFileTransferResource.java:191)
at
org.globus.transfer.reliable.service.ReliableFileTransferHome.create(ReliableFileTransferHome.java:126)
at
org.globus.transfer.reliable.service.factory.ReliableFileTransferFactoryService.createReliableFileTransfer(ReliableFileTransferFactoryService.java:249)
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:616)
at
org.globus.exec.service.exec.utils.LocalInvocationHelper.callService(LocalInvocationHelper.java:140)
at
org.globus.exec.service.exec.utils.LocalStagingHelper.submitStagingRequest(LocalStagingHelper.java:95)
at
org.globus.exec.service.exec.processing.handler.StageOutStateHandler.process(StageOutStateHandler.java:79)
at
org.globus.exec.service.exec.processing.handler.InternalStateHandler.processInternalState(InternalStateHandler.java:49)
at
org.globus.exec.service.exec.processing.StateMachine.processInternalState(StateMachine.java:121)
at
org.globus.exec.service.exec.processing.StateProcessingTask.run(StateProcessingTask.java:82)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2012-09-11T17:49:51.070-04:00 DEBUG utils.FaultUtils
[pool-1-thread-1,makeFault:541] Fault Class: class
org.globus.exec.generated.StagingFaultType
2012-09-11T17:49:51.070-04:00 DEBUG utils.FaultUtils
[pool-1-thread-1,makeFault:542] Resource Key: {
http://www.globus.org/namespaces/2008/03/gram/job}ResourceID=d69fb7c0-fc45-11e1-93da-f931d11c3d83
2012-09-11T17:49:51.070-04:00 DEBUG utils.FaultUtils
[pool-1-thread-1,makeFault:543] Description: Staging error for RSL element
fileStageOut.
2012-09-11T17:49:51.070-04:00 DEBUG utils.FaultUtils
[pool-1-thread-1,makeFault:545] Cause: java.rmi.RemoteException
2012-09-11T17:49:51.070-04:00 DEBUG utils.FaultUtils
[pool-1-thread-1,makeFault:549] State when failure occurred: StageOut
2012-09-11T17:49:51.070-04:00 DEBUG utils.FaultUtils
[pool-1-thread-1,makeFault:551] Script Command: StageOut
On Tue, Sep 11, 2012 at 6:05 PM, Adam Bazinet <[email protected]>wrote:
> Dear list and particularly GT 4.x and Condor GRAM users,
>
> To those of you who may be interested, I have confirmed that the Condor
> SEG is sensitive to the order and formatting of the elements in
> globus-condor.log. If I shift them around manually so that they conform to
> what a <c> block looks like with an older version of Condor, Globus
> properly picks up the fact that my jobs are complete. However, as it goes
> to stage out the files, I get an RFT failure saying the "Database driver is
> not initialized, Need to setup database". My question is: do I have
> something wrong with RFT in this Globus installation? This seems unlikely
> since I have several others configured the same way without any issue, and
> there are no problems staging files *in*. Does it have to do with my
> manually mucking around with the globus-condor.log file? A relevant bit of
> the container.log is below. I'd appreciate your input because regarding
> this and also a possible workaround for the SEG parsing problem (Condor
> version downgrade, modifications to SEG parsing code, or otherwise).
>
> thanks,
> Adam
>
>
>
> On Thu, Aug 30, 2012 at 4:09 PM, Adam Bazinet <[email protected]>wrote:
>
>> Hi all,
>>
>> I just installed a new GT 4.2.1 on a Condor resource, and while jobs run
>> and complete in Condor fine, the finished status is not being picked up by
>> Globus appropriately.
>>
>> Is the GT 4.2.1 sensitive to the order/formatting of the elements in
>> globus-condor.log?
>>
>> For example, here is a JobTerminatedEvent from globus-condor.log from an
>> older Condor/Globus installation that works properly:
>>
>> <c>
>> <a n="MyType"><s>JobTerminatedEvent</s></a>
>> <a n="EventTypeNumber"><i>5</i></a>
>> <a n="MyType"><s>JobTerminatedEvent</s></a>
>> <a n="EventTime"><s>2012-08-29T00:32:04</s></a>
>> <a n="Cluster"><i>18720</i></a>
>> <a n="Proc"><i>36</i></a>
>> <a n="Subproc"><i>0</i></a>
>> <a n="TerminatedNormally"><b v="t"/></a>
>> <a n="ReturnValue"><i>0</i></a>
>> <a n="RunLocalUsage"><s>Usr 0 00:00:00, Sys 0 00:00:00</s></a>
>> <a n="RunRemoteUsage"><s>Usr 0 07:01:33, Sys 0 00:00:13</s></a>
>> <a n="TotalLocalUsage"><s>Usr 0 00:00:00, Sys 0 00:00:00</s></a>
>> <a n="TotalRemoteUsage"><s>Usr 0 07:01:33, Sys 0 00:00:13</s></a>
>> <a n="SentBytes"><r>3.244000000000000E+04</r></a>
>> <a n="ReceivedBytes"><r>4.281464000000000E+06</r></a>
>> <a n="TotalSentBytes"><r>3.244000000000000E+04</r></a>
>> <a n="TotalReceivedBytes"><r>5.565903200000000E+07</r></a>
>> </c>
>>
>> and here is the one from the new resource that is NOT working properly:
>>
>> <c>
>> <a n="MyType"><s>JobTerminatedEvent</s></a>
>> <a n="TotalLocalUsage"><s>Usr 0 00:00:00, Sys 0 00:00:00</s></a>
>> <a n="Proc"><i>0</i></a>
>> <a n="EventTime"><s>2012-08-28T16:07:17</s></a>
>> <a n="TotalRemoteUsage"><s>Usr 0 00:00:00, Sys 0 00:00:00</s></a>
>> <a n="TotalReceivedBytes"><r>2.231476000000000E+06</r></a>
>> <a n="ReturnValue"><i>0</i></a>
>> <a n="RunRemoteUsage"><s>Usr 0 00:00:00, Sys 0 00:00:00</s></a>
>> <a n="RunLocalUsage"><s>Usr 0 00:00:00, Sys 0 00:00:00</s></a>
>> <a n="SentBytes"><r>3.979500000000000E+04</r></a>
>> <a n="Cluster"><i>20</i></a>
>> <a n="TotalSentBytes"><r>3.979500000000000E+04</r></a>
>> <a n="Subproc"><i>0</i></a>
>> <a n="CurrentTime"><e>time()</e></a>
>> <a n="EventTypeNumber"><i>5</i></a>
>> <a n="ReceivedBytes"><r>2.231476000000000E+06</r></a>
>> <a n="TerminatedNormally"><b v="t"/></a>
>> </c>
>>
>> Basically, the only variable that's different about this resource is that
>> it's running a newer version of Condor. My hunch is that broke
>> compatibility somewhere along the way. Can someone confirm this, or provide
>> another mechanism to debug? I'm attaching the container.log from the
>> resource in question, which has GRAM debugging enabled as some jobs came
>> in. It didn't really show me anything, though.
>>
>> thanks,
>> Adam
>>
>>
>
