2 Replies Latest reply on Nov 28, 2008 8:37 AM by dzulian

    [AbstractFileGateway] Composer <LocalFileMessageComposer> Fa

    dzulian

      I'm working on an integration project where ESB is responsible for:

      1: picking up XML message files in a remote host using an ftp-provider and writing them to a local directory.
      2: loading each file from the local dir using fs-provider,
      3: validating its XML message,
      4: consuming the message using hibernate,
      5: creating a result message to be returned to the sender,
      6: writing it to a success/error directory,
      7: loading the result message file using fs-provider,
      8: sending the return info through a web service.

      The problem seems to be on step 7, when multiple "return message files" are placed on the dir to be sent back to the sender, after working well with a couple of files I get the following exception:

      2008-11-13 16:17:11,154 ERROR [org.jboss.soa.esb.listeners.gateway.AbstractFileGateway] Composer <org.jboss.soa.esb.listeners.gateway.LocalFileMessageComposer> Failed.
      org.jboss.soa.esb.listeners.message.MessageDeliverException: Invalid File payload. File 'C:\message\loja\ok\9844_MsgUnidade_13112008_35501.msg.esbWorking' doesn't exist.
      at org.jboss.soa.esb.listeners.gateway.LocalFileMessageComposer.compose(LocalFileMessageComposer.java:63)
      at org.jboss.soa.esb.listeners.gateway.LocalFileMessageComposer.compose(LocalFileMessageComposer.java:44)
      at org.jboss.soa.esb.listeners.gateway.AbstractFileGateway.onSchedule(AbstractFileGateway.java:156)
      at org.jboss.soa.esb.schedule.ScheduleProvider$ESBScheduledJob.execute(ScheduleProvider.java:227)
      at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
      at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)

      Although the exception is raised, the process is completed and step 8 is executed, making it looks like there are two threads working on the same file, where one of them completes the entire pipeline while the other fails on step 7... though I've configured it to work with a single thread!

      my jboss-esb.xml looks like this:

      <?xml version = "1.0" encoding = "UTF-8"?>
      <jbossesb xmlns="http://anonsvn.labs.jboss.com/labs/jbossesb/trunk/product/etc/schemas/xml/jbossesb-1.0.1.xsd" parameterReloadSecs="5">
      
       <providers>
       <ftp-provider name="FTPprovider" hostname="${caravelas.ftp}">
       <ftp-bus busid="helloFTPChannel" >
       <ftp-message-filter
       username="caravelas"
       password="colombo"
       passive="false"
       directory="${caravelas.ftp.directory}"
       input-suffix=".msg"
       work-suffix=".esbWorking"
       post-delete="false"
       post-suffix=".COMPLETE"
       error-delete="false"
       error-suffix=".HAS_ERROR"/>
       </ftp-bus>
       </ftp-provider>
       <fs-provider name="FSprovider">
       <fs-bus busid="SucessoFileChannel" >
       <fs-message-filter
       directory="${caravelas.message.ok}"
       input-suffix=".msg"
       work-suffix=".esbWorking"
       post-delete="false"
       post-directory="${caravelas.message.ok}"
       post-suffix=".sentToEsb"
       error-delete="false"
       error-directory="${caravelas.message.ok}"
       error-suffix=".IN_ERROR"
       />
       </fs-bus>
       <fs-bus busid="ErroFileChannel" >
       <fs-message-filter
       directory="${caravelas.message.erro}"
       input-suffix=".msg"
       work-suffix=".esbWorking"
       post-delete="false"
       post-directory="${caravelas.message.erro}"
       post-suffix=".sentToEsb"
       error-delete="false"
       error-directory="${caravelas.message.erro}"
       error-suffix=".IN_ERROR"
       />
       </fs-bus>
       </fs-provider>
       <jms-provider name="JBossMQ" connection-factory="ConnectionFactory">
       <jms-bus busid="quickstartEsbChannel">
       <jms-message-filter dest-type="QUEUE" dest-name="queue/B"/>
       </jms-bus>
       <jms-bus busid="Business_Rules_ClientePFisica">
       <jms-message-filter dest-type="QUEUE" dest-name="queue/ConsumidorClientePFisicaService"/>
       </jms-bus>
       <jms-bus busid="Business_Rules_Linha">
       <jms-message-filter dest-type="QUEUE" dest-name="queue/ConsumidorLinhaService"/>
       </jms-bus>
       <jms-bus busid="Business_Rules_Familia">
       <jms-message-filter dest-type="QUEUE" dest-name="queue/ConsumidorFamiliaService"/>
       </jms-bus>
       <jms-bus busid="Business_Rules_Unidade">
       <jms-message-filter dest-type="QUEUE" dest-name="queue/ConsumidorUnidadeService"/>
       </jms-bus>
       <jms-bus busid="Queue_ERRO">
       <jms-message-filter dest-type="QUEUE" dest-name="queue/ERRO" />
       </jms-bus>
       <jms-bus busid="Queue_SUCESSO">
       <jms-message-filter dest-type="QUEUE" dest-name="queue/SUCESSO" />
       </jms-bus>
       <jms-bus busid="Queue_RETORNO_SUCESSO">
       <jms-message-filter dest-type="QUEUE" dest-name="queue/RetornoSucesso"/>
       </jms-bus>
       <jms-bus busid="Queue_RETORNO_ERRO">
       <jms-message-filter dest-type="QUEUE" dest-name="queue/RetornoErro"/>
       </jms-bus>
       </jms-provider>
       <schedule-provider name="cronExample">
       <cron-schedule scheduleid="cron-schedule" cronExpression="0/5 * * * * ?"/>
       </schedule-provider>
       </providers>
       <services>
       <service category="myCategory" name="myFileListener" description="Hello World File Action (esb listener)" >
       <listeners>
       <ftp-listener name="FtpGateway" busidref="helloFTPChannel" is-gateway="true" scheduleidref="cron-schedule" />
       <jms-listener name="helloWorldFileAction" busidref="quickstartEsbChannel" />
       </listeners>
       <actions>
       <action name="ValidaMensagem" class="com.colombo.esb.action.ValidaMensagem"/>
       <action name="ContentBasedRouter" class="org.jboss.soa.esb.actions.ContentBasedRouter">
       <property name="ruleSet" value="rotas.drl" />
       <property name="ruleReload" value="true" />
       <property name="destinations">
       <route-to destination-name="ConsumidorClientePFisicaService" service-category="ConsumidorServices" service-name="ConsumidorClientePFisicaService" />
       <route-to destination-name="ConsumidorLinhaService" service-category="ConsumidorServices" service-name="ConsumidorLinhaService"/>
       <route-to destination-name="ConsumidorFamiliaService" service-category="ConsumidorServices" service-name="ConsumidorFamiliaService" />
       <route-to destination-name="ConsumidorUnidadeService" service-category="ConsumidorServices" service-name="ConsumidorUnidadeService" />
       </property>
       <property name="object-paths">
       <object-path esb="body.mensagem_tipo" />
       </property>
       </action>
       </actions>
       </service>
       <service category="ConsumidorServices" name="ConsumidorClientePFisicaService" description="Consumidor de ClientePFisica">
       <listeners>
       <jms-listener name="Business_Rules_ClientePFisica" busidref="Business_Rules_ClientePFisica"/>
       </listeners>
       <actions mep="OneWay">
       <action name="ConsumidorClientePFisica" class="com.colombo.esb.action.ConsumidorClientePFisica"/>
       </actions>
       </service>
       <service category="ConsumidorServices" name="ConsumidorLinhaService" description="Consumidor de Linha">
       <listeners>
       <jms-listener name="Business_Rules_Linha" busidref="Business_Rules_Linha"/>
       </listeners>
       <actions mep="OneWay">
       <action name="ConsumidorLinha" class="com.colombo.esb.action.ConsumidorLinha"/>
       </actions>
       </service>
       <service category="ConsumidorServices" name="ConsumidorFamiliaService" description="Consumidor de Familia">
       <listeners>
       <jms-listener name="Business_Rules_Familia" busidref="Business_Rules_Familia"/>
       </listeners>
       <actions mep="OneWay">
       <action name="ConsumidorFamilia" class="com.colombo.esb.action.ConsumidorFamilia"/>
       </actions>
       </service>
       <service category="ConsumidorServices" name="ConsumidorUnidadeService" description="Consumidor de Unidade">
       <listeners>
       <jms-listener name="Business_Rules_Unidade" busidref="Business_Rules_Unidade"/>
       </listeners>
       <actions mep="OneWay">
       <action name="ConsumidorUnidade" class="com.colombo.esb.action.ConsumidorUnidade"/>
       </actions>
       </service>
       <service category="controle" name="Erro" description="gera msg erro">
       <listeners>
       <jms-listener name="Queue_ERRO" busidref="Queue_ERRO" is-gateway="false"/>
       </listeners>
       <actions mep="OneWay">
       <action name="ErroAction" class="com.colombo.esb.action.ErroAction">
       <property name="directory" value="${caravelas.message.erro}"/>
       </action>
       </actions>
       </service>
       <service category="controle" name="Sucesso" description="gera msg Sucesso">
       <listeners>
       <jms-listener name="Queue_SUCESSO" busidref="Queue_SUCESSO" is-gateway="false"/>
       </listeners>
       <actions mep="OneWay">
       <action name="SucessoAction" class="com.colombo.esb.action.SucessoAction">
       <property name="directory" value="${caravelas.message.ok}"/>
       </action>
       </actions>
       </service>
       <service category="resposta" name="RetornoSucesso" description="gera Retorno Sucesso">
       <listeners>
       <fs-listener name="SucessoGateway" busidref="SucessoFileChannel" is-gateway="true" poll-frequency-seconds="10"/>
       <jms-listener name="Queue_RETORNO" busidref="Queue_RETORNO_SUCESSO"/>
       </listeners>
       <actions mep="OneWay">
       <action name="geraRetorno" class="com.colombo.esb.action.GeraRetornoMatriz" />
       </actions>
       </service>
       <service category="resposta" name="RetornoErro" description="gera Retorno Erro">
       <listeners>
       <fs-listener name="ErroGateway" busidref="ErroFileChannel" is-gateway="true" poll-frequency-seconds="10"/>
       <jms-listener name="Queue_RETORNO" busidref="Queue_RETORNO_ERRO"/>
       </listeners>
       <actions mep="OneWay">
       <action name="geraRetorno" class="com.colombo.esb.action.GeraRetornoMatriz" />
       </actions>
       </service>
       </services>
      </jbossesb>


      and we're using a "caravelas-service.xml" file to load the properties containing dir paths and ftp info, it looks like this:
      <?xml version="1.0" encoding="UTF-8"?>
      <server>
       <mbean code="org.jboss.varia.property.SystemPropertiesService" name="jboss.util:type=Service,name=SystemProperties">
       <attribute name="Properties">
       caravelas.ftp=100.1.1.137
       caravelas.ftp.directory=/home/caravelas/ftp/message/out/001
       caravelas.message.ok=C:/message/loja/ok
       caravelas.message.erro=c:/message/loja/erro
       </attribute>
       </mbean>
      </server>


      and a drools file to route the messages:

      package com.jboss.soa.esb.routing.cbr
      
      #list any import classes here.
      import org.jboss.soa.esb.message.Message;
      import org.jboss.soa.esb.message.format.MessageType;
      
      #declare any global variables here
      global java.util.List destinations;
      
      rule "ClientePFisica"
       when
       mensagem_tipo:String(toString == "MsgClientePFisica")
       then
       System.out.println("MENSAGEM MsgClientePFisica");
       destinations.add("ConsumidorClientePFisicaService");
      end
      
      rule "Linha"
       when
       mensagem_tipo:String(toString == "MsgLinha")
       then
       System.out.println("MENSAGEM MsgLinha");
       destinations.add("ConsumidorLinhaService");
      end
      
      rule "Familia"
       when
       mensagem_tipo:String(toString == "MsgFamilia")
       then
       System.out.println("MENSAGEM MsgFamilia");
       destinations.add("ConsumidorFamiliaService");
      end
      
      rule "Unidade"
       when
       mensagem_tipo:String(toString == "MsgUnidade")
       then
       System.out.println("MENSAGEM MsgUnidade");
       destinations.add("ConsumidorUnidadeService");
      end


      Please, let me know if any other information is needed.

      Douglas

        • 1. Re: [AbstractFileGateway] Composer <LocalFileMessageComposer
          kconner

          Thanks for posting here.

          Which version of the ESB are you using? Do you have any log files showing the error?

          There was a recent issue which sounds similar to your problem, https://jira.jboss.org/jira/browse/JBESB-2079, but this would not explain why you are seeing multiple threads processing the files.

          • 2. Re: [AbstractFileGateway] Composer <LocalFileMessageComposer
            dzulian

            Hi Kevin,

            I'm sorry for taking so long to reply your question, I thought I would get an e-mail once a reply was posted, but I didn't get that e-mail. Anyway...

            The environment is as follows:
            JBoss AS 4.2.2.GA
            JBoss ESB 4.4.GA
            Windows XP SP3

            Here is a more comprehensive log, I have the entire log if you need, it has 2.6MB compacted.

            2008-11-13 16:17:08,808 INFO [com.colombo.esb.action.ConsumidorLinha] Consumidor Familia...
            2008-11-13 16:17:09,059 INFO [com.colombo.esb.action.ValidaMensagem] MensagemID: 9858
            2008-11-13 16:17:09,059 INFO [com.colombo.esb.action.ValidaMensagem] DataCriacao: 2008-11-13T16:09:45.000-03:00
            2008-11-13 16:17:09,059 INFO [com.colombo.esb.action.ValidaMensagem] Recuperou conteudo da mensagem na Loja
            2008-11-13 16:17:09,059 INFO [com.colombo.esb.action.ValidaMensagem] Validando corpo da mensagem na Loja...
            2008-11-13 16:17:09,590 INFO [com.colombo.esb.action.AbstractGeraArquivoRetornoAction] Mensagem de retorno gerada!
            2008-11-13 16:17:09,606 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onInput
            2008-11-13 16:17:09,606 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onInput
            2008-11-13 16:17:09,606 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] pipeline process for message: header:
            [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/SUCESSO/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.initial :
            org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties
            jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties
            jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties
            jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted :
            false/>, <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: 6133e426-42a4-4c48-b3f4-f590a06f2268 RelatesTo:
            jms:correlationID#6133e426-42a4-4c48-b3f4-f590a06f2268 ]
            2008-11-13 16:17:09,606 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] executing processor 0
            org.jboss.soa.esb.listeners.message.OverriddenActionLifecycleProcessor@1f69fc7 header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/SUCESSO/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url :
            127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>,
            <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties
            jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: 6133e426-42a4-4c48-b3f4-f590a06f2268 RelatesTo:
            jms:correlationID#6133e426-42a4-4c48-b3f4-f590a06f2268 ]
            2008-11-13 16:17:09,606 INFO [com.colombo.esb.action.AbstractGeraArquivoRetornoAction] Gerando mensagem de sucesso para retorno...
            2008-11-13 16:17:09,809 INFO [com.colombo.esb.action.ConsumidorLinha] Familia: 7
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 1)
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.SQL]
             select
             this_.COD_FAMILIA as COD1_794_1_,
             this_.DATA_ULT_ALTERACAO as DATA2_794_1_,
             this_.USUARIO_ULT_ALTERACAO as USUARIO3_794_1_,
             this_.DESCRICAO as DESCRICAO794_1_,
             this_.ORDEM as ORDEM794_1_,
             this_.FLG_ATIVO as FLG6_794_1_,
             this_.COD_LINHA as COD8_794_1_,
             this_.TIPO_SAIDA as TIPO7_794_1_,
             linhaentit2_.COD_LINHA as COD1_793_0_,
             linhaentit2_.DATA_ULT_ALTERACAO as DATA2_793_0_,
             linhaentit2_.USUARIO_ULT_ALTERACAO as USUARIO3_793_0_,
             linhaentit2_.DESCRICAO as DESCRICAO793_0_,
             linhaentit2_.ORDEM as ORDEM793_0_,
             linhaentit2_.FLG_ATIVO as FLG6_793_0_,
             linhaentit2_.FLG_VENDA as FLG7_793_0_
             from
             FAMILIA this_
             inner join
             LINHA linhaentit2_
             on this_.COD_LINHA=linhaentit2_.COD_LINHA
             where
             this_.COD_FAMILIA = ?
            2008-11-13 16:17:09,809 INFO [STDOUT] Hibernate:
             select
             this_.COD_FAMILIA as COD1_794_1_,
             this_.DATA_ULT_ALTERACAO as DATA2_794_1_,
             this_.USUARIO_ULT_ALTERACAO as USUARIO3_794_1_,
             this_.DESCRICAO as DESCRICAO794_1_,
             this_.ORDEM as ORDEM794_1_,
             this_.FLG_ATIVO as FLG6_794_1_,
             this_.COD_LINHA as COD8_794_1_,
             this_.TIPO_SAIDA as TIPO7_794_1_,
             linhaentit2_.COD_LINHA as COD1_793_0_,
             linhaentit2_.DATA_ULT_ALTERACAO as DATA2_793_0_,
             linhaentit2_.USUARIO_ULT_ALTERACAO as USUARIO3_793_0_,
             linhaentit2_.DESCRICAO as DESCRICAO793_0_,
             linhaentit2_.ORDEM as ORDEM793_0_,
             linhaentit2_.FLG_ATIVO as FLG6_793_0_,
             linhaentit2_.FLG_VENDA as FLG7_793_0_
             from
             FAMILIA this_
             inner join
             LINHA linhaentit2_
             on this_.COD_LINHA=linhaentit2_.COD_LINHA
             where
             this_.COD_FAMILIA = ?
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.colombo.caravelas.entidade.LinhaEntity#1],
            EntityKey[com.colombo.caravelas.entidade.FamiliaEntity#7]
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 2)
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 1)
            (open ResultSets: 0, globally: 0)]
            2008-11-13 16:17:09,809 DEBUG [com.colombo.caravelas.hibernate.CaravelasConnectionProvider] ######## Fechou a conexaoorg.jboss.resource.adapter.jdbc.WrappedConnection@1b82f06
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 1)
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2008-11-13 16:17:09,809 DEBUG [org.hibernate.SQL]
             select
             this_.COD_LINHA as COD1_793_0_,
             this_.DATA_ULT_ALTERACAO as DATA2_793_0_,
             this_.USUARIO_ULT_ALTERACAO as USUARIO3_793_0_,
             this_.DESCRICAO as DESCRICAO793_0_,
             this_.ORDEM as ORDEM793_0_,
             this_.FLG_ATIVO as FLG6_793_0_,
             this_.FLG_VENDA as FLG7_793_0_
             from
             LINHA this_
             where
             this_.COD_LINHA = ?
            2008-11-13 16:17:09,809 INFO [STDOUT] Hibernate:
             select
             this_.COD_LINHA as COD1_793_0_,
             this_.DATA_ULT_ALTERACAO as DATA2_793_0_,
             this_.USUARIO_ULT_ALTERACAO as USUARIO3_793_0_,
             this_.DESCRICAO as DESCRICAO793_0_,
             this_.ORDEM as ORDEM793_0_,
             this_.FLG_ATIVO as FLG6_793_0_,
             this_.FLG_VENDA as FLG7_793_0_
             from
             LINHA this_
             where
             this_.COD_LINHA = ?
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.colombo.caravelas.entidade.LinhaEntity#1]
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 2)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 1)
            (open ResultSets: 0, globally: 0)]
            2008-11-13 16:17:09,825 DEBUG [com.colombo.caravelas.hibernate.CaravelasConnectionProvider] ######## Fechou a conexaoorg.jboss.resource.adapter.jdbc.WrappedConnection@77a7f0
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.transaction.JDBCTransaction] begin
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.transaction.JDBCTransaction] current autocommit status: true
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.transaction.JDBCTransaction] disabling autocommit
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.transaction.JDBCTransaction] commit
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.LinhaEntity.familia#1], was: [com.colombo.caravelas.entidade.LinhaEntity.familia#1] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.LinhaEntity.promocao#1], was: [com.colombo.caravelas.entidade.LinhaEntity.promocao#1] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.LinhaEntity.promocaoBrindeValor#1], was: [com.colombo.caravelas.entidade.LinhaEntity.promocaoBrindeValor#1] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#1], was: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#1] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#1], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#1] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#1], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#1] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#1], was: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#1] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#2], was: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#2] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#2], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#2] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#2], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#2] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#2], was: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#2] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#3], was: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#3] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#3], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#3] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#3], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#3] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#3], was: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#3] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#4], was: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#4] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#4], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#4] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#4], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#4] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#4], was: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#4] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#5], was: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#5] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#5], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#5] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#5], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#5] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#5], was: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#5] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#6], was: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#6] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#6], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#6] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#6], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#6] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#6], was: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#6] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#7], was: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#7] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#7], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#7] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#7], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#7] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#7], was: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#7] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#8], was: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#8] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#8], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#8] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#8], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#8] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#8], was: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#8] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#9], was: [com.colombo.caravelas.entidade.FamiliaEntity.grupo#9] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#9], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocao#9] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#9], was: [com.colombo.caravelas.entidade.FamiliaEntity.promocaoBrindeValor#9] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.engine.Collections] Collection found: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#9], was: [com.colombo.caravelas.entidade.FamiliaEntity.especificacao#9] (uninitialized)
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 10 objects
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 39 collections
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] listing entities:
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.FamiliaEntity{flgAtivo=false,
            linha=com.colombo.caravelas.entidade.LinhaEntity#1, dataUltAlteracao=2008-11-13 15:06:43, ordem=0, especificacao=<uninitialized>,
            grupo=<uninitialized>, codFamilia=6, promocao=<uninitialized>, descricao=NAO USAR, usuarioUltAlteracao=, promocaoBrindeValor=<uninitialized>, tipoSaida=EM}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.FamiliaEntity{flgAtivo=false,
            linha=com.colombo.caravelas.entidade.LinhaEntity#1, dataUltAlteracao=2008-11-13 09:13:38, ordem=0, especificacao=<uninitialized>,
            grupo=<uninitialized>, codFamilia=4, promocao=<uninitialized>, descricao=NAO USAR, usuarioUltAlteracao=, promocaoBrindeValor=<uninitialized>, tipoSaida=EM}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.FamiliaEntity{flgAtivo=false,
            linha=com.colombo.caravelas.entidade.LinhaEntity#1, dataUltAlteracao=2008-11-13 15:06:33, ordem=0, especificacao=<uninitialized>,
            grupo=<uninitialized>, codFamilia=2, promocao=<uninitialized>, descricao=NAO USAR, usuarioUltAlteracao=, promocaoBrindeValor=<uninitialized>, tipoSaida=EM}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.FamiliaEntity{flgAtivo=false,
            linha=com.colombo.caravelas.entidade.LinhaEntity#1, dataUltAlteracao=2008-11-13 15:06:48, ordem=0, especificacao=<uninitialized>,
            grupo=<uninitialized>, codFamilia=8, promocao=<uninitialized>, descricao=NAO USAR, usuarioUltAlteracao=, promocaoBrindeValor=<uninitialized>, tipoSaida=EM}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.FamiliaEntity{flgAtivo=false,
            linha=com.colombo.caravelas.entidade.LinhaEntity#1, dataUltAlteracao=2008-11-13 15:06:41, ordem=0, especificacao=<uninitialized>,
            grupo=<uninitialized>, codFamilia=5, promocao=<uninitialized>, descricao=NAO USAR, usuarioUltAlteracao=, promocaoBrindeValor=<uninitialized>, tipoSaida=EM}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.FamiliaEntity{flgAtivo=false,
            linha=com.colombo.caravelas.entidade.LinhaEntity#1, dataUltAlteracao=2008-11-13 15:06:46, ordem=0, especificacao=<uninitialized>,
            grupo=<uninitialized>, codFamilia=7, promocao=<uninitialized>, descricao=NAO USAR, usuarioUltAlteracao=, promocaoBrindeValor=<uninitialized>, tipoSaida=EM}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.FamiliaEntity{flgAtivo=false,
            linha=com.colombo.caravelas.entidade.LinhaEntity#1, dataUltAlteracao=2008-11-13 15:06:50, ordem=0, especificacao=<uninitialized>,
            grupo=<uninitialized>, codFamilia=9, promocao=<uninitialized>, descricao=NAO USAR, usuarioUltAlteracao=, promocaoBrindeValor=<uninitialized>, tipoSaida=EM}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.FamiliaEntity{flgAtivo=false,
            linha=com.colombo.caravelas.entidade.LinhaEntity#1, dataUltAlteracao=2008-11-13 15:06:37, ordem=0, especificacao=<uninitialized>,
            grupo=<uninitialized>, codFamilia=3, promocao=<uninitialized>, descricao=NAO USAR, usuarioUltAlteracao=, promocaoBrindeValor=<uninitialized>, tipoSaida=EM}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.FamiliaEntity{flgAtivo=true,
            linha=com.colombo.caravelas.entidade.LinhaEntity#1, dataUltAlteracao=2008-11-13 15:06:30, ordem=0, especificacao=<uninitialized>,
            grupo=<uninitialized>, codFamilia=1, promocao=<uninitialized>, descricao=SERVICOS MOn, usuarioUltAlteracao=, promocaoBrindeValor=<uninitialized>, tipoSaida=EM}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.pretty.Printer] com.colombo.caravelas.entidade.LinhaEntity{flgAtivo=false,
            dataUltAlteracao=2008-04-15 00:00:00, ordem=0, flgVenda=true, promocao=<uninitialized>, descricao=SERVICOS_teste, codLinha=1,
            familia=<uninitialized>, usuarioUltAlteracao=APCOL, promocaoBrindeValor=<uninitialized>}
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.transaction.JDBCTransaction] re-enabling autocommit
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.transaction.JDBCTransaction] committed JDBC Connection
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2008-11-13 16:17:09,825 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 1) (open ResultSets: 0, globally: 0)]
            2008-11-13 16:17:09,825 DEBUG [com.colombo.caravelas.hibernate.CaravelasConnectionProvider] ######## Fechou a conexaoorg.jboss.resource.adapter.jdbc.WrappedConnection@67aeb7
            2008-11-13 16:17:09,825 INFO [com.colombo.esb.action.ConsumidorLinha] Familia importada!
            2008-11-13 16:17:10,012 DEBUG [org.jboss.soa.esb.listeners.ListenerUtil] No value specified for postRename attribute - Using default value: 'true'
            2008-11-13 16:17:10,012 DEBUG [org.jboss.soa.esb.listeners.ListenerUtil] No value specified for postDir attribute - Using default value: '/home/caravelas/ftp/message/out/001'
            2008-11-13 16:17:10,059 INFO [com.colombo.esb.action.ValidaMensagem] Validacao Concluida!
            2008-11-13 16:17:10,059 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] executing processor 1
            org.jboss.soa.esb.actions.ContentBasedRouter@12f34b2 header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/B/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url :
            127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>,
            <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties
            jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: 9f27de71-d451-4ef5-a53c-33b583a13d38 RelatesTo:
            jms:correlationID#9f27de71-d451-4ef5-a53c-33b583a13d38 ]
            2008-11-13 16:17:10,059 DEBUG [org.jboss.soa.esb.message.mapping.ObjectMapper] expression=body.mensagem_tipo value=MsgLinha
            2008-11-13 16:17:10,059 DEBUG [org.jboss.internal.soa.esb.services.rules.RuleServiceFactory] Going to load org.jboss.internal.soa.esb.services.rules.DroolsRuleService
            2008-11-13 16:17:10,059 INFO [STDOUT] MENSAGEM MsgLinha
            2008-11-13 16:17:10,059 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:10,059 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:10,075 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
            2008-11-13 16:17:10,075 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier deliveryMode: 2, peristent:true
            2008-11-13 16:17:10,075 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : 9f27de71-d451-4ef5-a53c-33b583a13d38
            2008-11-13 16:17:10,075 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : 9f27de71-d451-4ef5-a53c-33b583a13d38
            2008-11-13 16:17:10,091 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onInput
            2008-11-13 16:17:10,091 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onInput
            2008-11-13 16:17:10,091 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] pipeline process for message: header: [ To: JMSEpr [ PortReference
            < <wsa:Address jms://127.0.0.1:1099/queue/B/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>,
            <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>,
            <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>,
            <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>,
            <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: bbfdc4dd-d9cf-4a23-8dd8-c40eaf00c91d RelatesTo:
            jms:correlationID#bbfdc4dd-d9cf-4a23-8dd8-c40eaf00c91d ]
            2008-11-13 16:17:10,091 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] executing processor 0 com.colombo.esb.action.ValidaMensagem@3a6012 header:
            [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/B/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.initial :
            org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties
            jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties
            jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties
            jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: bbfdc4dd-d9cf-4a23-8dd8-c40eaf00c91d
            RelatesTo: jms:correlationID#bbfdc4dd-d9cf-4a23-8dd8-c40eaf00c91d ]
            2008-11-13 16:17:10,091 INFO [com.colombo.esb.action.ValidaMensagem] Lendo objeto da mensagem na Loja...
            2008-11-13 16:17:10,325 DEBUG [org.jboss.internal.soa.esb.services.registry.CachingRegistryInterceptor] Cache hit for service controle:Sucesso
            2008-11-13 16:17:10,325 DEBUG [org.jboss.soa.esb.client.ServiceInvoker] EPR=JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/SUCESSO/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url :
            127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>,
            <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties
            jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] XML=<wsa:From xmlns:wsa="http://schemas.xmlsoap.org/ws/2004/08/addressing">
            <wsa:Address>jms://127.0.0.1:1099/queue/SUCESSO</wsa:Address><wsa:ReferenceProperties><jbossesb:java.naming.factory.initial
            xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">org.jnp.interfaces.NamingContextFactory</jbossesb:java.naming.factory.initial>
            <jbossesb:java.naming.provider.url xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">127.0.0.1:1099</jbossesb:java.naming.provider.url>
            <jbossesb:java.naming.factory.url.pkgs xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">org.jnp.interfaces</jbossesb:java.naming.factory.url.pkgs>
            <jbossesb:destination-type xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">queue</jbossesb:destination-type><jbossesb:specification-version
            xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">1.1</jbossesb:specification-version><jbossesb:connection-factory
            xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">ConnectionFactory</jbossesb:connection-factory><jbossesb:persistent
            xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">true</jbossesb:persistent><jbossesb:acknowledge-mode
            xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">AUTO_ACKNOWLEDGE</jbossesb:acknowledge-mode><jbossesb:transacted
            xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">false</jbossesb:transacted><jbossesb:type xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">
            urn:jboss/esb/epr/type/jms</jbossesb:type></wsa:ReferenceProperties></wsa:From>
            2008-11-13 16:17:10,325 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:10,325 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:10,325 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
            2008-11-13 16:17:10,325 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier deliveryMode: 2, peristent:true
            2008-11-13 16:17:10,325 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : f0ffdd21-2160-473f-8f70-ee519fccd119
            2008-11-13 16:17:10,341 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onInput
            2008-11-13 16:17:10,341 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onInput
            2008-11-13 16:17:10,341 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] pipeline process for message: header: [ To:
            JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/ConsumidorLinhaService/>, <wsa:ReferenceProperties
            jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>,
            <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>,
            <wsa:ReferenceProperties jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>,
            <wsa:ReferenceProperties jbossesb:transacted : false/>, <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ]
            MessageID: 2f2f75d7-2d2e-4095-8bdf-a4fbc6fecfc1 RelatesTo: jms:correlationID#2f2f75d7-2d2e-4095-8bdf-a4fbc6fecfc1 ]
            2008-11-13 16:17:10,341 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] executing processor 0 com.colombo.esb.action.ConsumidorLinha@1cc7d48
            header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/ConsumidorLinhaService/>, <wsa:ReferenceProperties
            jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>,
            <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>,
            <wsa:ReferenceProperties jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>,
            <wsa:ReferenceProperties jbossesb:transacted : false/>, <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ]
            MessageID: 2f2f75d7-2d2e-4095-8bdf-a4fbc6fecfc1 RelatesTo: jms:correlationID#2f2f75d7-2d2e-4095-8bdf-a4fbc6fecfc1 ]
            2008-11-13 16:17:10,575 INFO [STDOUT] ########################
            2008-11-13 16:17:10,575 INFO [STDOUT] C:/message/loja/ok
            2008-11-13 16:17:11,123 INFO [com.colombo.esb.action.ValidaMensagem] MensagemID: 9859
            2008-11-13 16:17:11,123 INFO [com.colombo.esb.action.ValidaMensagem] DataCriacao: 2008-11-13T16:09:45.000-03:00
            2008-11-13 16:17:11,123 INFO [com.colombo.esb.action.ValidaMensagem] Recuperou conteudo da mensagem na Loja
            2008-11-13 16:17:11,123 INFO [com.colombo.esb.action.ValidaMensagem] Validando corpo da mensagem na Loja...
            2008-11-13 16:17:11,138 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:11,138 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:11,138 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:11,138 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:11,138 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
            2008-11-13 16:17:11,138 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier deliveryMode: 2, peristent:true
            
            
            2008-11-13 16:17:11,138 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : 469496db-6639-45dd-a44e-498c7956466f
            2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onInput
            2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onInput
            2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] pipeline process for message: header: [
            To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/RetornoSucesso/>, <wsa:ReferenceProperties
            jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>,
            <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>,
            <wsa:ReferenceProperties jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>,
            <wsa:ReferenceProperties jbossesb:transacted : false/>, <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ]
            MessageID: 469496db-6639-45dd-a44e-498c7956466f RelatesTo: jms:correlationID#469496db-6639-45dd-a44e-498c7956466f ]
            2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] executing processor 0
            org.jboss.soa.esb.listeners.message.OverriddenActionLifecycleProcessor@19754cb header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/RetornoSucesso/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>,
            <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>,
            <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>,
            <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>,
            <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: 469496db-6639-45dd-a44e-498c7956466f
            RelatesTo: jms:correlationID#469496db-6639-45dd-a44e-498c7956466f ]
            2008-11-13 16:17:11,154 INFO [com.colombo.esb.action.GeraRetornoMatriz] Gerando retorno para Mariz
            2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.util.FileUtil] Unable to perform local rename of file 'C:\message\loja\ok\9844_MsgUnidade_13112008_35501.msg' to
             'C:\message\loja\ok\cc0f4273-db97-4524-8302-47d7a3390e18.9844_MsgUnidade_13112008_35501.msg.cc0f4273-db97-4524-8302-47d7a3390e18'. Unable to move file.
             2008-11-13 16:17:11,154 ERROR [org.jboss.soa.esb.listeners.gateway.AbstractFileGateway] Composer <org.jboss.soa.esb.listeners.gateway.LocalFileMessageComposer> Failed.
             org.jboss.soa.esb.listeners.message.MessageDeliverException: Invalid File payload. File 'C:\message\loja\ok\9844_MsgUnidade_13112008_35501.msg.esbWorking' doesn't exist.
             at org.jboss.soa.esb.listeners.gateway.LocalFileMessageComposer.compose(LocalFileMessageComposer.java:63)
             at org.jboss.soa.esb.listeners.gateway.LocalFileMessageComposer.compose(LocalFileMessageComposer.java:44)
             at org.jboss.soa.esb.listeners.gateway.AbstractFileGateway.onSchedule(AbstractFileGateway.java:156)
             at org.jboss.soa.esb.schedule.ScheduleProvider$ESBScheduledJob.execute(ScheduleProvider.java:227)
             at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
             at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)
             2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.util.FileUtil] Unable to rename file 'C:\message\loja\ok\9844_MsgUnidade_13112008_35501.msg.esbWorking' to
             'C:\message\loja\ok\9844_MsgUnidade_13112008_35501.msg.IN_ERROR'. 'C:\message\loja\ok\9844_MsgUnidade_13112008_35501.msg.esbWorking' doesn't exist.
            2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:11,154 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:11,170 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
            2008-11-13 16:17:11,170 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier deliveryMode: 2, peristent:true
            2008-11-13 16:17:11,170 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : 4bae76cd-f770-4758-a195-484885137a8e
            2008-11-13 16:17:11,170 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:11,170 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:11,185 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:11,185 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:11,185 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
            2008-11-13 16:17:11,185 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier deliveryMode: 2, peristent:true
            2008-11-13 16:17:11,185 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : caf52435-47c0-42b8-b9c4-9be64312e8f3
            2008-11-13 16:17:11,201 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:11,201 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:11,201 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:11,201 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:11,201 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
            2008-11-13 16:17:11,201 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier deliveryMode: 2, peristent:true
            2008-11-13 16:17:11,201 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : bea01517-ea92-41e5-811d-1f43ca7c4eb3
            2008-11-13 16:17:11,420 INFO [com.colombo.esb.action.ConsumidorLinha] Consumidor Linha...
            2008-11-13 16:17:11,701 INFO [com.colombo.esb.action.AbstractGeraArquivoRetornoAction] Mensagem de retorno gerada!
            2008-11-13 16:17:11,717 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onInput
            2008-11-13 16:17:11,717 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onInput
            2008-11-13 16:17:11,717 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] pipeline process for message: header: [
            To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/SUCESSO/>, <wsa:ReferenceProperties
            jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>,
            <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>,
            <wsa:ReferenceProperties jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>,
            <wsa:ReferenceProperties jbossesb:transacted : false/>, <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ]
            MessageID: eccf6347-e58b-4919-a930-0b7dd97d3d77 RelatesTo: jms:correlationID#eccf6347-e58b-4919-a930-0b7dd97d3d77 ]
            2008-11-13 16:17:11,717 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] executing processor 0 org.jboss.soa.esb.listeners.message.OverriddenActionLifecycleProcessor@1f69fc7
            header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/SUCESSO/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>,
            <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>,
            <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>,
            <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>,
            <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: eccf6347-e58b-4919-a930-0b7dd97d3d77 RelatesTo: jms:correlationID#eccf6347-e58b-4919-a930-0b7dd97d3d77 ]
            2008-11-13 16:17:11,717 INFO [com.colombo.esb.action.AbstractGeraArquivoRetornoAction] Gerando mensagem de sucesso para retorno...
            2008-11-13 16:17:11,905 DEBUG [org.jboss.internal.soa.esb.services.registry.CachingRegistryInterceptor] Cache hit for service controle:Sucesso
            2008-11-13 16:17:11,905 DEBUG [org.jboss.soa.esb.client.ServiceInvoker] EPR=JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/SUCESSO/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>,
            <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>,
            <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>,
            <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>,
            <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] XML=<wsa:From xmlns:wsa="http://schemas.xmlsoap.org/ws/2004/08/addressing">
            <wsa:Address>jms://127.0.0.1:1099/queue/SUCESSO</wsa:Address><wsa:ReferenceProperties>
            <jbossesb:java.naming.factory.initial xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">org.jnp.interfaces.NamingContextFactory
            </jbossesb:java.naming.factory.initial><jbossesb:java.naming.provider.url xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">127.0.0.1:1099
            </jbossesb:java.naming.provider.url><jbossesb:java.naming.factory.url.pkgs xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">org.jnp.interfaces
            </jbossesb:java.naming.factory.url.pkgs><jbossesb:destination-type xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">queue</jbossesb:destination-type>
            <jbossesb:specification-version xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">1.1</jbossesb:specification-version>
            <jbossesb:connection-factory xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">ConnectionFactory</jbossesb:connection-factory>
            <jbossesb:persistent xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">true</jbossesb:persistent>
            <jbossesb:acknowledge-mode xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">AUTO_ACKNOWLEDGE
            </jbossesb:acknowledge-mode><jbossesb:transacted xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">false</jbossesb:transacted>
            <jbossesb:type xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">urn:jboss/esb/epr/type/jms</jbossesb:type></wsa:ReferenceProperties></wsa:From>
            2008-11-13 16:17:11,905 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:11,905 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:11,920 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
            2008-11-13 16:17:11,920 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier deliveryMode: 2, peristent:true
            2008-11-13 16:17:11,920 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : e5a1e35d-f7ee-4d7c-89eb-10800b27480c
            2008-11-13 16:17:11,920 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onInput
            2008-11-13 16:17:11,920 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onInput
            2008-11-13 16:17:11,920 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] pipeline process for message:
            header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/ConsumidorFamiliaService/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>,
            <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>,
            <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>,
            <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>,
            <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: f7076ec1-1a4a-487c-858e-3caf7c07414b
            RelatesTo: jms:correlationID#f7076ec1-1a4a-487c-858e-3caf7c07414b ]
            2008-11-13 16:17:11,920 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] executing processor 0 com.colombo.esb.action.ConsumidorFamilia@1bc35fa
            header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/ConsumidorFamiliaService/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>,
            <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>,
            <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>,
            <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>,
            <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: f7076ec1-1a4a-487c-858e-3caf7c07414b
            RelatesTo: jms:correlationID#f7076ec1-1a4a-487c-858e-3caf7c07414b ]
            2008-11-13 16:17:12,155 INFO [com.colombo.esb.action.ValidaMensagem] Validacao Concluida!
            2008-11-13 16:17:12,155 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] executing processor 1 org.jboss.soa.esb.actions.ContentBasedRouter@12f34b2
            header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/B/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>,
            <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>,
            <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>,
            <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>,
            <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: bbfdc4dd-d9cf-4a23-8dd8-c40eaf00c91d
            RelatesTo: jms:correlationID#bbfdc4dd-d9cf-4a23-8dd8-c40eaf00c91d ]
            2008-11-13 16:17:12,155 DEBUG [org.jboss.soa.esb.message.mapping.ObjectMapper] expression=body.mensagem_tipo value=MsgLinha
            2008-11-13 16:17:12,155 DEBUG [org.jboss.internal.soa.esb.services.rules.RuleServiceFactory] Going to load org.jboss.internal.soa.esb.services.rules.DroolsRuleService
            2008-11-13 16:17:12,155 INFO [STDOUT] MENSAGEM MsgLinha
            2008-11-13 16:17:12,155 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onOutput
            2008-11-13 16:17:12,155 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onOutput
            2008-11-13 16:17:12,155 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
            2008-11-13 16:17:12,155 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier deliveryMode: 2, peristent:true
            2008-11-13 16:17:12,155 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : bbfdc4dd-d9cf-4a23-8dd8-c40eaf00c91d
            2008-11-13 16:17:12,155 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setting outgoing JMSCorreletionID to : bbfdc4dd-d9cf-4a23-8dd8-c40eaf00c91d
            2008-11-13 16:17:12,170 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.MetaDataFilter@1ed1c32.onInput
            2008-11-13 16:17:12,170 DEBUG [org.jboss.soa.esb.filter.FilterManager] FilterManager calling org.jboss.internal.soa.esb.message.filter.GatewayFilter@1d63e96.onInput
            2008-11-13 16:17:12,170 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] pipeline process for message:
            header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/B/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>,
            <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>,
            <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>,
            <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>,
            <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: a4552661-4597-4ea2-a609-c4f68110d39e
            RelatesTo: jms:correlationID#a4552661-4597-4ea2-a609-c4f68110d39e ]
            2008-11-13 16:17:12,170 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] executing processor 0 com.colombo.esb.action.ValidaMensagem@3a6012
            header: [ To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/B/>,
            <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>,
            <wsa:ReferenceProperties jbossesb:java.naming.provider.url : 127.0.0.1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jnp.interfaces/>,
            <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>,
            <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>,
            <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>,
            <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: a4552661-4597-4ea2-a609-c4f68110d39e
            RelatesTo: jms:correlationID#a4552661-4597-4ea2-a609-c4f68110d39e ]
            2008-11-13 16:17:12,170 INFO [com.colombo.esb.action.ValidaMensagem] Lendo objeto da mensagem na Loja...
            2008-11-13 16:17:12,530 DEBUG [org.jbpm.job.executor.JobExecutorThread] acquiring jobs for execution...
            2008-11-13 16:17:12,530 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories
            '[tx, message, scheduler, logging, persistence, authentication]'
            2008-11-13 16:17:12,530 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext@b9cff8
            2008-11-13 16:17:12,530 DEBUG [org.jbpm.JbpmContext] start user JTA transaction
            2008-11-13 16:17:12,530 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
            2008-11-13 16:17:12,530 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 5024169298042880
            2008-11-13 16:17:12,530 DEBUG [org.jbpm.persistence.db.DbPersistenceService] using current hibernate session
            SessionImpl(PersistenceContext[entityKeys=[],collectionKeys=[]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[]
            collectionRemovals=[] collectionUpdates=[]])
            2008-11-13 16:17:12,530 DEBUG [org.jbpm.job.executor.JobExecutorThread] querying for acquirable job...
            2008-11-13 16:17:12,530 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 1)
            2008-11-13 16:17:12,530 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2008-11-13 16:17:12,530 DEBUG [org.hibernate.SQL] select top ? job0_.ID_ as ID1_248_, job0_.VERSION_ as VERSION3_248_, job0_.DUEDATE_ as DUEDATE4_248_,
            job0_.PROCESSINSTANCE_ as PROCESSI5_248_, job0_.TOKEN_ as TOKEN6_248_, job0_.TASKINSTANCE_ as TASKINST7_248_, job0_.ISSUSPENDED_ as ISSUSPEN8_248_,
            job0_.ISEXCLUSIVE_ as ISEXCLUS9_248_, job0_.LOCKOWNER_ as LOCKOWNER10_248_, job0_.LOCKTIME_ as LOCKTIME11_248_, job0_.EXCEPTION_ as EXCEPTION12_248_,
            job0_.RETRIES_ as RETRIES13_248_, job0_.NAME_ as NAME14_248_, job0_.REPEAT_ as REPEAT15_248_, job0_.TRANSITIONNAME_ as TRANSIT16_248_,
            job0_.ACTION_ as ACTION17_248_, job0_.GRAPHELEMENTTYPE_ as GRAPHEL18_248_, job0_.GRAPHELEMENT_ as GRAPHEL19_248_, job0_.NODE_ as NODE20_248_,
            job0_.CLASS_ as CLASS2_248_ from JBPM_JOB job0_ where (job0_.LOCKOWNER_ is null or job0_.LOCKOWNER_=?) and job0_.RETRIES_>0 and job0_.DUEDATE_<=? and
            job0_.ISSUSPENDED_<>1 order by job0_.DUEDATE_ asc
            2008-11-13 16:17:12,530 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 2)
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 1) (open ResultSets: 0, globally: 0)]
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.job.executor.JobExecutorThread] no acquirable jobs in job table
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext@b9cff8
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.jta.JtaDbPersistenceService@11ea4b8
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.JbpmContext] end user JTA transaction
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.JbpmContext] end jta transation with COMMIT
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService@61ad41
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.job.executor.JobExecutorThread] obtained locks on following jobs: []
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories
            '[tx, message, scheduler, logging, persistence, authentication]'
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext@b5a458
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.JbpmContext] start user JTA transaction
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 5024169298108416
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.persistence.db.DbPersistenceService] using current hibernate session SessionImpl(PersistenceContext[entityKeys=[],
            collectionKeys=[]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]])
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 1)
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.SQL] select top ? job0_.ID_ as ID1_248_, job0_.VERSION_ as VERSION3_248_, job0_.DUEDATE_ as DUEDATE4_248_,
            job0_.PROCESSINSTANCE_ as PROCESSI5_248_, job0_.TOKEN_ as TOKEN6_248_, job0_.TASKINSTANCE_ as TASKINST7_248_, job0_.ISSUSPENDED_ as ISSUSPEN8_248_,
            job0_.ISEXCLUSIVE_ as ISEXCLUS9_248_, job0_.LOCKOWNER_ as LOCKOWNER10_248_, job0_.LOCKTIME_ as LOCKTIME11_248_, job0_.EXCEPTION_ as EXCEPTION12_248_,
            job0_.RETRIES_ as RETRIES13_248_, job0_.NAME_ as NAME14_248_, job0_.REPEAT_ as REPEAT15_248_, job0_.TRANSITIONNAME_ as TRANSIT16_248_, job0_.ACTION_ as ACTION17_248_,
            job0_.GRAPHELEMENTTYPE_ as GRAPHEL18_248_, job0_.GRAPHELEMENT_ as GRAPHEL19_248_, job0_.NODE_ as NODE20_248_, job0_.CLASS_ as CLASS2_248_ from JBPM_JOB job0_
            where (job0_.LOCKOWNER_ is null or job0_.LOCKOWNER_=?) and job0_.RETRIES_>0 and job0_.ISSUSPENDED_<>1 order by job0_.DUEDATE_ asc
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 2)
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 1)
            (open ResultSets: 0, globally: 0)]
            2008-11-13 16:17:12,546 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2008-11-13 16:17:12,546 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext@b5a458
            2008-11-13