Problem with helloworld_ftp quickstart?

[zurchman]

Is there some problem with the ftp quickstart?

18:00:21,868 INFO [JBoss4ESBDeployer] create esb service, Quickstart_helloworld_FTP_action.esb
18:00:21,895 INFO [quickstart_helloworld_ftp_esb] Bound to JNDI name: queue/quickstart_helloworld_ftp_esb
18:00:21,956 INFO [AbstractFileGateway] No value specified for: max-millis-for-response - This will be an 'inbound-only' gateway
18:00:22,063 INFO [JDBCDataStore] Generated token 'authToken:9F418370-3738-11DD-A0C9-EA40ECA7871B' for user: 'jbossesb/JBoss ESB User'
18:00:22,285 INFO [QuartzScheduler] Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED started.

This is all I get in the server log. I'm running the regular "runtest", not the read-only one.

The file is being delivered to the configured directory by ftp.

Looking at jboss-esb.xml, I suspect the wiring.

[beve]

Hi,

can you tell us what version you are using and I'll take a look.

Thanks,

/Daniel

[zurchman]

JBossESB 4.3.GA deployed in JBoss AS 4.2.2.GA

[beve]

Hi,

I've get tried with JBossESB 4.3.GA deployed on JBoss AS 4..2.2.GA and get the following output:

21:37:25,211 INFO [STDOUT] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&
21:37:25,214 INFO [STDOUT] Body: Hello World In A File (for Hello World FTP Action test)
21:37:25,214 INFO [STDOUT] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&

Do you see any errors or messages in server/default/log/server.log ?

What does you samples/quickstarts/conf/quickstarts.properties look like?

Regards,

/Daniel

[zurchman]

Thanks for looking into this. So far all the other quickstarts have run fine.

quickstarts.properties:

org.jboss.esb.server.home=[path_to_my_server]

# JBossAS server name. If not set defaults to 'default'
# Will override the same property name from install/deployment.properties
org.jboss.esb.server.config=default


# If you are running the ftp tests then you must complete the following
jbossesb.ftp.hostname=localhost
jbossesb.ftp.username=[myusername]
jbossesb.ftp.password=[mypassword]
jbossesb.ftp.directory=/tmp

ftp.log

Jun 11 16:47:55 ftpd[16604]: connection from localhost to localhost
Jun 11 16:47:55 ftpd[16604]: FTP LOGIN FROM localhost as me (class: real, type: REAL)
Jun 11 16:47:55 ftpd[16604]: Data traffic: 0 bytes in 0 files
Jun 11 16:47:55 ftpd[16604]: Total traffic: 476 bytes in 0 transfers
Jun 11 16:47:57 ftpd[16606]: connection from localhost to localhost
 Jun 11 16:47:57 ftpd[16606]: FTP LOGIN FROM localhost as me (class: real, type: REAL)
 Jun 11 16:47:57 ftpd[16606]: Data traffic: 55 bytes in 1 file
 Jun 11 16:47:57 ftpd[16606]: Total traffic: 707 bytes in 1 transfer
Jun 11 16:48:00 ftpd[16612]: connection from localhost to localhost
Jun 11 16:48:00 ftpd[16612]: FTP LOGIN FROM localhost as me (class: real, type: REAL)
Jun 11 16:48:00 ftpd[16612]: Data traffic: 0 bytes in 0 files
Jun 11 16:48:00 ftpd[16612]: Total traffic: 476 bytes in 0 transfers
Jun 11 16:48:05 ftpd[16623]: connection from localhost to localhost
Jun 11 16:48:05 5 ftpd[16623]: FTP LOGIN FROM localhost as me (class: real, type: REAL)
Jun 11 16:48:05 ftpd[16623]: Data traffic: 0 bytes in 0 files

No errors in server.log, but there are a few interesting messages:

2008-06-11 16:24:17,760 DEBUG [org.jboss.system.ServiceController] starting service jboss.esb:deployment=Quickstart_helloworld_FTP_action.esb
2008-06-11 16:24:17,760 DEBUG [org.jboss.soa.esb.listeners.config.JBoss4ESBDeployment] Starting jboss.esb:deployment=Quickstart_helloworld_FTP_action.esb
2008-06-11 16:24:17,760 DEBUG [org.jboss.soa.esb.lifecycle.LifecycleResourceManager] Associating deploymentName Quickstart_helloworld_FTP_action.esb with identity: ID-19
2008-06-11 16:24:17,814 DEBUG [org.jboss.soa.esb.listeners.lifecycle.AbstractManagedLifecycle] terminationPeriod value 60000
2008-06-11 16:24:17,817 DEBUG [org.jboss.soa.esb.listeners.lifecycle.AbstractManagedLifecycle] terminationPeriod value 60000
2008-06-11 16:24:17,818 DEBUG [org.jboss.soa.esb.listeners.ListenerUtil] No value specified for postRename attribute - Using default value: 'true'
2008-06-11 16:24:17,818 DEBUG [org.jboss.soa.esb.listeners.ListenerUtil] No value specified for postDir attribute - Using default value: '/tmp'
2008-06-11 16:24:17,818 INFO [org.jboss.soa.esb.listeners.gateway.AbstractFileGateway] No value specified for: max-millis-for-response - This will be an 'inbound-only' gateway
 2008-06-11 16:24:17,824 DEBUG [org.jboss.soa.esb.listeners.ListenerUtil] No value specified for postRename attribute - Using default value: 'true'
 2008-06-11 16:24:17,824 DEBUG [org.jboss.soa.esb.listeners.ListenerUtil] No value specified for postDir attribute - Using default value: '/tmp'
2008-06-11 16:24:18,253 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] Using mep: null, oneWay: false, defaultProcessing: true
2008-06-11 16:24:18,253 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] Registering action class org.jboss.soa.esb.samples.quickstart.helloworldftpaction.MyAction
2008-06-11 16:24:18,253 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] Using overridden action lifecycle processor for org.jboss.soa.esb.samples.quickstart.helloworldftpaction.MyAction
2008-06-11 16:24:18,254 DEBUG [org.jboss.soa.esb.lifecycle.LifecycleResource] Creating resource using factory: org.jboss.soa.esb.couriers.CourierFactory$LifecycleCourierFactory@65d6f5 with identity ID-19
...

[beve]

Hmm, there is nothing in the logs that indicate an error or anything unusual.

The file is being delivered to the configured directory by ftp.

So, when you run 'ant runtest' you can see the file in /tmp but they are not getting picked up and set to .COMPLETE?

Can you post the jboss-esb.xml (not the jboss-esb-unfiltered.xml) so I can compare it with what I'm running.

Thanks,

/Daniel

[zurchman]

Here's the file.

The listener name in the service made me suspect the wiring.

I'm running this on OS X. I was using /tmp for the ftp directory, but /tmp is a symlink, so I changed that.

I can't get the static_router quickstart to run either, so it certainly looks like there's a problem somewhere in my enviornment.

<?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="localhost" >
 <ftp-bus busid="helloFTPChannel" >
 <ftp-message-filter
 username="myname"
 password="mypassword"
 passive="false"
 directory="/Users/myname/jbossftp"
 input-suffix=".dat"
 work-suffix=".esbWorking"
 post-delete="false"
 post-suffix=".COMPLETE"
 error-delete="false"
 error-suffix=".HAS_ERROR"
 />
 </ftp-bus>
 </ftp-provider>

 <jms-provider name="JBossMQ"
 connection-factory="ConnectionFactory"
 jndi-context-factory="org.jnp.interfaces.NamingContextFactory"
 jndi-URL="localhost" >

 <jms-bus busid="quickstartEsbChannel">
 <jms-message-filter
 dest-type="QUEUE"
 dest-name="queue/quickstart_helloworld_ftp_esb"
 selector="source='fromHelloworldFTPAction'"
 />
 </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"
 maxThreads="1"
 is-gateway="true"
 scheduleidref="cron-schedule"/>

 <jms-listener name="helloWorldFileAction"
 busidref="quickstartEsbChannel"
 maxThreads="1"
 />
 </listeners>
 <actions>
 <action name="action1"
 class="org.jboss.soa.esb.samples.quickstart.helloworldftpaction.MyAction"
 process="displayMessage,playWithMessage"
 />
 </actions>
 </service>
 </services>

</jbossesb>

[beve]

yeah, it does sound like there is something with the quickstarts that use ftp that are causing you issues. You have no problem running other quickstart (that don't use ftp), is that correct?

I'm not using OS X myself and don't have access to one either, but I believe that one or two others in the team do. I'll see if I can get someone to try them out.

Regards,

Daniel

[kconner]

"zurchman" wrote:
The listener name in the service made me suspect the wiring.

The listener name is fine, although it shouldn't really say file :)

Please try

ant undeploy
ant clean
ant deploy

My guess would be that your deployed version has a different directory for the service.

[zurchman]

I've been undeploying and deploying with every test cycle.

I think it's time turn up the trace level.

Can you suggest some classes and levels that might turn something up?

Thanks

[kconner]

You should have the debug logs included in the system.log file.

If that is not showing anything then there are two ways to progress this

The first is to watch the network traffic and see what requests/responses are hitting your ftp server. This may show an issue with the interactions (which ftp server are you using BTW?)

The second is to send me an email and I will send you a small test client. You can run this (standalone) against your FTP server and see if that shows up anything.

[zurchman]

(which ftp server are you using BTW?)

I'm using the localhost OS X ftp server. I get the same result using a remote AIX ftp server, so I'm guessing the problem is not ftp.

Maybe I'm missing something. Could you explain how this quickstart is supposed to work?

The first is to watch the network traffic and see what requests/responses are hitting your ftp server.

Here's the pattern from the ftp.log

Jun 10 16:41:50 ftpd[8894]: connection from localhost to localhost
Jun 10 16:41:50 ftpd[8894]: FTP LOGIN FROM localhost as zurchman (class: real, type: REAL)
Jun 10 16:41:50 ftpd[8894]: Data traffic: 0 bytes in 0 files
Jun 10 16:41:50 ftpd[8894]: Total traffic: 476 bytes in 0 transfers
Jun 10 16:41:55 ftpd[8900]: connection from localhost to localhost
Jun 10 16:41:55 ftpd[8900]: FTP LOGIN FROM localhost as zurchman (class: real, type: REAL)
Jun 10 16:41:55 ftpd[8900]: Data traffic: 0 bytes in 0 files
Jun 10 16:41:55 ftpd[8900]: Total traffic: 476 bytes in 0 transfers

Jun 10 16:41:59 ftpd[8921]: connection from localhost to localhost
 Jun 10 16:41:59 ftpd[8921]: FTP LOGIN FROM localhost as zurchman (class: real, type: REAL)
 Jun 10 16:41:59 ftpd[8921]: Data traffic: 55 bytes in 1 file
 Jun 10 16:41:59 ftpd[8921]: Total traffic: 707 bytes in 1 transfer

Jun 10 16:42:00 ftpd[8922]: connection from localhost to localhost
Jun 10 16:42:00 ftpd[8922]: FTP LOGIN FROM localhost as zurchman (class: real, type: REAL)
Jun 10 16:42:00 ftpd[8922]: Data traffic: 0 bytes in 0 files
Jun 10 16:42:00 ftpd[8922]: Total traffic: 476 bytes in 0 transfers
Jun 10 16:42:05 ftpd[8933]: connection from localhost to localhost
Jun 10 16:42:05 ftpd[8933]: FTP LOGIN FROM localhost as zurchman (class: real, type: REAL)
Jun 10 16:42:05 ftpd[8933]: Data traffic: 0 bytes in 0 files
Jun 10 16:42:05 ftpd[8933]: Total traffic: 476 bytes in 0 transfers
Jun 10 16:42:10 ftpd[8939]: connection from localhost to localhost
Jun 10 16:42:10 ftpd[8939]: FTP LOGIN FROM localhost as zurchman (class: real, type: REAL)
Jun 10 16:42:10 ftpd[8939]: Data traffic: 0 bytes in 0 files
Jun 10 16:42:10 ftpd[8939]: Total traffic: 476 bytes in 0 transfers
Jun 10 16:42:15 ftpd[8950]: connection from localhost to localhost
Jun 10 16:42:15 ftpd[8950]: FTP LOGIN FROM localhost as zurchman (class: real, type: REAL)
Jun 10 16:42:15 ftpd[8950]: Data traffic: 0 bytes in 0 files
Jun 10 16:42:15 ftpd[8950]: Total traffic: 476 bytes in 0 transfers
6:42:50 ftpd[9016]: Total traffic: 476 bytes in 0 transfers

send me an email and I will send you a small test client.

Watch your inbox. :)

Thanks.

[marklittle]

I use MacOS X (10.5.3) with PureFtpD. I'll give this a try.

[marklittle]

I ran with PureFTPd and got the following:

15:19:02,982 INFO [JBoss4ESBDeployer] create esb service, Quickstart_helloworld_FTP_action.esb
15:19:02,995 INFO [quickstart_helloworld_ftp_esb] Bound to JNDI name: queue/quickstart_helloworld_ftp_esb
15:19:03,083 INFO [AbstractFileGateway] No value specified for: max-millis-for-response - This will be an 'inbound-only' gateway
15:19:03,555 INFO [JDBCDataStore] Generated token 'authToken:01A56AD0-3AE6-11DD-AAD0-DA8A3B744F5C' for user: 'jbossesb/JBoss ESB User'
15:19:03,609 INFO [JDBCDataStore] Generated token 'authToken:01AC96C0-3AE6-11DD-96C0-B100EB1499F9' for user: 'jbossesb/JBoss ESB User'
15:19:04,082 INFO [QuartzScheduler] Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED started.
15:19:15,219 INFO [STDOUT]
&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&
15:19:15,221 INFO [STDOUT] Body: Hello World In A File (for Hello World FTP Action test)
15:19:15,221 INFO [STDOUT] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&
15:19:15,230 WARN [ActionProcessingPipeline] No reply to address defined for reply message! To: JMSEpr [ PortReference < <wsa:Address jms://127.0.0.1:1099/queue/quickstart_helloworld_ftp_esb/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : localhost/>, <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:message-selector : source='fromHelloworldFTPAction'/>, <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: 5d7e49bc-60ca-414c-9f62-a231467392d2 RelatesTo: jms:correlationID#5d7e49bc-60ca-414c-9f62-a231467392d2

[zurchman]

Hi

It looks like there's some sort of problem with my Network environment.

I sent Kevin a sftptest stack trace that should enable him to narrow down the problem.

Just out of curiosity: what directory are you using in quickstarts.properties?

Thanks.