Adam What database do you use for RFT? Is it Postgresql or derby? On Sep 11, 2012, at 5:08 PM, Adam Bazinet wrote:
> 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-f931d11c3d83
> changed 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
>
>
>
--Ravi
smime.p7s
Description: S/MIME cryptographic signature
