search

radical-cybertools / radical.pilot

RADICAL-Pilot
http://radical-cybertools.github.io/radical-pilot/index.html
Other
54 stars 23 forks source link

process I/O failed #278

Closed marksantcroos closed 9 years ago

marksantcroos commented 9 years ago

(problem reported by Francis Liu)

I've had a problem when trying to run tutorial example in section 5.1:

[mypyenv0] fengl@talat (/home/grad03/fengl/pilot) % setenv RADICAL_PILOT_DBURL
"mongodb://ec2-184-72-89-141.compute-1.amazonaws.com:24242/"
[mypyenv0] fengl@talat (/home/grad03/fengl/pilot) % python ./simple_bot.py
Initializing Pilot Manager ...
Submitting Compute Pilot to Pilot Manager ...
AN ERROR OCCURRED: process I/O failed:
 (/home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/saga/utils/pty_process.py +512 (read)  :  raise se.NoSuccess
("process I/O failed: %s" % self.tail))
marksantcroos commented 9 years ago

Hi Francis, Not sure what is happening here, can you try with the following enabled? export RADICAL_PILOT_VERBOSE=DEBUG Thanks

Francis-Liu commented 9 years ago

Yep.

[mypyenv0] fengl@talat (/home/grad03/fengl/pilot) % python ./simple_bot.py
2014:08:05 09:51:46 radical.pilot.MainProcess: [INFO    ] radical.pilot version: 0.18
2014:08:05 09:51:47 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/lrz.json
2014:08:05 09:51:47 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/das4.json
2014:08:05 09:51:47 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/localhost.json
2014:08:05 09:51:47 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/iu.json
2014:08:05 09:51:47 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/futuregrid.json
2014:08:05 09:51:47 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/xsede.json
2014:08:05 09:51:47 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/ncar.json
2014:08:05 09:51:47 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/epsrc.json
2014:08:05 09:51:47 radical.pilot.MainProcess: [INFO    ] New Session created{'database_url': 'mongodb://ec2-184-72-89-141.compute-1.amazonaws.com:24242/', 'database_name': 'radicalpilot', 'last_reconnect': None, 'uid': '53e0ef834256c017ad9ac864', 'created': datetime.datetime(2014, 8, 5, 14, 51, 47, 470499)}.
Initializing Pilot Manager ...
2014:08:05 09:51:48 radical.pilot.MainProcess: [DEBUG   ] Worker thread (ID: Thread-1[140462078379776]) for PilotManager 53e0ef834256c017ad9ac865 started.
Submitting Compute Pilot to Pilot Manager ...
2014:08:05 09:51:48 radical.pilot.PilotLauncherWorker-1: [DEBUG   ] Connected to MongoDB. Serving requests for PilotManager 53e0ef834256c017ad9ac865.
2014:08:05 09:51:48 radical.pilot.MainProcess: [DEBUG   ] PTYShell init <saga.utils.pty_shell.PTYShell object at 0x1fa5d50>
2014:08:05 09:51:48 radical.pilot.MainProcess: [INFO    ] PTY prompt pattern: [\$#%>\]]\s*$
2014:08:05 09:51:48 radical.pilot.MainProcess: [DEBUG   ] open master pty for [ssh] [fs2.das4.science.uva.nl] fengl: /usr/bin/env TERM=vt100  "/usr/bin/ssh"   -t -o IdentityFile=/home/grad03/fengl/.ssh/id_rsa   -o ControlMaster=yes -o ControlPath=/tmp/saga_ssh_fengl_%h_%p.ctrl  fs2.das4.science.uva.nl'
2014:08:05 09:51:48 radical.pilot.MainProcess: [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x215d710>
2014:08:05 09:51:48 radical.pilot.MainProcess: [INFO    ] running: /usr/bin/env TERM=vt100 /usr/bin/ssh -t -o IdentityFile=/home/grad03/fengl/.ssh/id_rsa -o ControlMaster=yes -o ControlPath=/tmp/saga_ssh_fengl_%h_%p.ctrl fs2.das4.science.uva.nl
2014:08:05 09:51:48 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 09:51:49 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 09:51:49 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   28] ( printf 'HELLO_%d_SAGA\n' 1\n)
2014:08:05 09:51:50 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 09:51:50 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   28] ( printf 'HELLO_%d_SAGA\n' 2\n)
2014:08:05 09:51:51 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 09:51:51 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   28] ( printf 'HELLO_%d_SAGA\n' 3\n)
2014:08:05 09:51:52 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 09:51:52 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   28] ( printf 'HELLO_%d_SAGA\n' 4\n)
2014:08:05 09:51:53 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 09:51:53 radical.pilot.MainProcess: [DEBUG   ] write: [    5] [   28] ( printf 'HELLO_%d_SAGA\n' 5\n)
2014:08:05 09:51:54 radical.pilot.MainProcess: [DEBUG   ] read : [    5] [   63] (ssh_exchange_identification: Connection closed by remote host\n)
AN ERROR OCCURRED: too frequent login attempts, or sshd misconfiguration: process I/O failed: ssh_exchange_identification: Connection closed by remote host
 ((ssh_exchange_identification: Connection closed by remote host
)) (/home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/saga/utils/pty_exceptions.py +50 (translate_exception)  :  e = se.AuthenticationFailed ("too frequent login attempts, or sshd misconfiguration: %s" % cmsg))
2014:08:05 09:51:54 radical.pilot.MainProcess: [DEBUG   ] PTYProcess del  <saga.utils.pty_process.PTYProcess object at 0x215d710>
2014:08:05 09:51:54 radical.pilot.MainProcess: [DEBUG   ] PTYShell del  <saga.utils.pty_shell.PTYShell object at 0x1fa5d50>
[mypyenv0] fengl@talat (/home/grad03/fengl/pilot) %
andre-merzky commented 9 years ago

2014:08:05 09:51:48 radical.pilot.MainProcess: [INFO ] running: /usr/bin/env TERM=vt100 /usr/bin/ssh -t -o IdentityFile=/home/grad03/fengl/.ssh/id_rsa -o ControlMaster=yes -o ControlPath=/tmp/saga_sshfengl%h_%p.ctrl fs2.das4.science.uva.nl

This seems to connect to a site in Amsterdam which we used for our tutorials -- are you sure to have a login there?

Sorry for the mangled error message though: ssh does not make it easy to distinguish between timeout and failed login...

Francis-Liu commented 9 years ago

I'm sure I don't have a login there.

I will install MongoDB locally and try again.

Thanks! Mark

andre-merzky commented 9 years ago

Ah, wait -- that is not the mongodb connection -- that is the resource on which you attempt to spawn a pilot! Our default mongodb is open, you should not have problems accessing that (modulo firewall setups).

marksantcroos commented 9 years ago

On 05 Aug 2014, at 17:04 , Andre Merzky notifications@github.com wrote: Ah, wait -- that is not the mongodb connection -- that is the resource on which you attempt to spawn a pilot! Our default mongodb is open, you should not have problems accessing that (modulo firewall setups).

Indeed, the tutorial is "outdated", we have a ticket on that, sorry for the confusion.

Francis, in simply_bot.py, can you change:

pdesc.resource = "fs2.das4.science.uva.nl" # NOTE: This is a "label", not a hostname

into:

pdesc.resource = "localhost" # NOTE: This is a "label", not a hostname

and try again?

The example will now try to run on your localhost.

Francis-Liu commented 9 years ago

It seems OK now. But how long does this example take to finish? It has already paused at the last line "Copying agent ..." for about 5 minutes.

[mypyenv0] fengl@talat (/home/grad03/fengl/pilot) % python ./simple_bot.py                                                                    
2014:08:05 10:11:09 radical.pilot.MainProcess: [INFO    ] radical.pilot version: 0.18
2014:08:05 10:11:10 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/lrz.json
2014:08:05 10:11:10 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/das4.json
2014:08:05 10:11:10 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/localhost.json
2014:08:05 10:11:10 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/iu.json
2014:08:05 10:11:10 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/futuregrid.json
2014:08:05 10:11:10 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/xsede.json
2014:08:05 10:11:10 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/ncar.json
2014:08:05 10:11:10 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/epsrc.json
2014:08:05 10:11:11 radical.pilot.MainProcess: [INFO    ] New Session created{'database_url': 'mongodb://ec2-184-72-89-141.compute-1.amazonaws.com:24242/', 'database_name': 'radicalpilot', 'last_reconnect': None, 'uid': '53e0f40e4256c01a4c5c8eeb', 'created': datetime.datetime(2014, 8, 5, 15, 11, 10, 974934)}.
Initializing Pilot Manager ...
2014:08:05 10:11:11 radical.pilot.MainProcess: [DEBUG   ] Worker thread (ID: Thread-1[139871588173568]) for PilotManager 53e0f40f4256c01a4c5c8eec started.Submitting Compute Pilot to Pilot Manager ...

2014:08:05 10:11:11 radical.pilot.PilotLauncherWorker-1: [DEBUG   ] Connected to MongoDB. Serving requests for PilotManager 53e0f40f4256c01a4c5c8eec.
Initializing Unit Manager ...
2014:08:05 10:11:11 radical.pilot.MainProcess: [DEBUG   ] Worker thread (ID: Thread-2[139871579780864]) for UnitManager 53e0f40f4256c01a4c5c8eee started.
2014:08:05 10:11:11 radical.pilot.MainProcess: [INFO    ] Loaded scheduler: DirectSubmissionScheduler.
Registering Compute Pilot with Unit Manager ...
Submit Compute Units to Unit Manager ...
2014:08:05 10:11:11 radical.pilot.PilotLauncherWorker-1: [INFO    ] Launching ComputePilot {u'state': u'PendingLaunch', u'commands': [], u'description': {u'project': None, u'resource': u'localhost', u'queue': None, u'sandbox': None, u'cleanup': True, u'pilot_agent_priv': None, u'memory': None, u'cores': 1, u'runtime': 5}, u'sagajobid': None, u'started': None, u'cores_per_node': None, u'output_transfer_started': None, u'sandbox': u'file://localhost/home/grad03/fengl/radical.pilot.sandbox/pilot-53e0f40f4256c01a4c5c8eed/', u'submitted': datetime.datetime(2014, 8, 5, 15, 11, 11, 524000), u'output_transfer_finished': None, u'finished': None, u'pilotmanager': u'53e0f40f4256c01a4c5c8eec', u'unitmanager': u'53e0f40f4256c01a4c5c8eee', u'statehistory': [{u'timestamp': datetime.datetime(2014, 8, 5, 15, 11, 11, 524000), u'state': u'PendingLaunch'}], u'wu_queue': [], u'heartbeat': None, u'input_transfer_started': None, u'_id': ObjectId('53e0f40f4256c01a4c5c8eed'), u'input_transfer_finished': None, u'nodes': None, u'log': []}
2014:08:05 10:11:11 radical.pilot.PilotLauncherWorker-1: [INFO    ] Using pilot agent /home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/agent/radical-pilot-agent-multicore.py
2014:08:05 10:11:11 radical.pilot.PilotLauncherWorker-1: [INFO    ] Using bootstrapper /home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/bootstrapper/default_bootstrapper.sh
2014:08:05 10:11:11 radical.pilot.PilotLauncherWorker-1: [DEBUG   ] Creating agent sandbox 'file://localhost/home/grad03/fengl/radical.pilot.sandbox/pilot-53e0f40f4256c01a4c5c8eed/'.
2014:08:05 10:11:11 radical.pilot.InputFileTransferWorker-1: [DEBUG   ] Connected to MongoDB. Serving requests for UnitManager 53e0f40f4256c01a4c5c8eee.
2014:08:05 10:11:11 radical.pilot.InputFileTransferWorker-2: [DEBUG   ] Connected to MongoDB. Serving requests for UnitManager 53e0f40f4256c01a4c5c8eee.2014:08:05 10:11:11 radical.pilot.OutputFileTransferWorker-1: [DEBUG   ] Connected to MongoDB. Serving requests for UnitManager 53e0f40f4256c01a4c5c8eee.

2014:08:05 10:11:11 radical.pilot.OutputFileTransferWorker-2: [DEBUG   ] Connected to MongoDB. Serving requests for UnitManager 53e0f40f4256c01a4c5c8eee.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] Scheduled ComputeUnits ['53e0f40f4256c01a4c5c8eef', '53e0f40f4256c01a4c5c8ef0', '53e0f40f4256c01a4c5c8ef1', '53e0f40f4256c01a4c5c8ef2', '53e0f40f4256c01a4c5c8ef3', '53e0f40f4256c01a4c5c8ef4', '53e0f40f4256c01a4c5c8ef5', '53e0f40f4256c01a4c5c8ef6', '53e0f40f4256c01a4c5c8ef7', '53e0f40f4256c01a4c5c8ef8'] for execution on ComputePilot '53e0f40f4256c01a4c5c8eed'.
Waiting for CUs to complete ...
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] ComputePilot '53e0f40f4256c01a4c5c8eed' state changed from 'PendingLaunch' to 'Launching'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8eef' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8ef0' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8ef1' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8ef2' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8ef3' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8ef4' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8ef5' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8ef6' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8ef7' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:12 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e0f40f4256c01a4c5c8ef8' state changed from 'New' to 'PendingExecution'.
2014:08:05 10:11:14 radical.pilot.PilotLauncherWorker-1: [DEBUG   ] Copying bootstrapper 'file://localhost//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/bootstrapper/default_bootstrapper.sh' to agent sandbox (file://localhost/home/grad03/fengl/radical.pilot.sandbox/pilot-53e0f40f4256c01a4c5c8eed/).
2014:08:05 10:11:15 radical.pilot.PilotLauncherWorker-1: [DEBUG   ] Copying agent 'file://localhost//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/agent/radical-pilot-agent-multicore.py' to agent sandbox (file://localhost/home/grad03/fengl/radical.pilot.sandbox/pilot-53e0f40f4256c01a4c5c8eed/).
marksantcroos commented 9 years ago

On 05 Aug 2014, at 17:18 , Francis-Liu notifications@github.com wrote:

It seems OK now. But how long does this example take to finish? It has already paused at the last line "Copying agent ..." for about 5 minutes.

That should not take that long unfortunately.

Can you check in /home/grad03/fengl/radical.pilot.sandbox/pilot-53e0f40f4256c01a4c5c8eed/ if you see home hints in AGENT.[STDOUT|STDERR|LOG]?

Francis-Liu commented 9 years ago

From the timestamp I can tell those copyings were actually done instantly. But right now the application is still hanged.

fengl@talat (/home/grad03/fengl/radical.pilot.sandbox/pilot-53e0f40f4256c01a4c5c8eed) % ls -l
total 83
-rwx------+ 1 fengl grad 11117 Aug  5 10:11 default_bootstrapper.sh*
-rw-------+ 1 fengl grad 72003 Aug  5 10:11 radical-pilot-agent.py
marksantcroos commented 9 years ago

Hmmm, puzzling. Can you also try with an additional:

export SAGA_VERBOSE=DEBUG
Francis-Liu commented 9 years ago 
[mypyenv0] fengl@talat (/home/grad03/fengl/pilot) % python ./simple_bot.py | tee simple_bot.out
2014:08:05 14:47:58 radical.pilot.MainProcess: [INFO    ] radical.pilot version: 0.18
2014:08:05 14:47:58 16323  MainThread   saga                  : [INFO    ] saga-python     version: 0.17
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.context.myproxy
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.context.myproxy for saga.Context API with URL scheme(s) ['myproxy://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.context.x509
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.context.x509 for saga.Context API with URL scheme(s) ['x509://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.context.ssh
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.context.ssh for saga.Context API with URL scheme(s) ['ssh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.context.userpass
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.context.userpass for saga.Context API with URL scheme(s) ['userpass://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.shell.shell_job
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.shell.shell_job for saga.job.Service API with URL scheme(s) ['fork://', 'local://', 'ssh://', 'gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.shell.shell_job for saga.job.Job API with URL scheme(s) ['fork://', 'local://', 'ssh://', 'gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.shell.shell_file
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.shell.shell_file for saga.namespace.Directory API with URL scheme(s) ['file://', 'local://', 'sftp://', 'gsisftp://', 'ssh://', 'gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.shell.shell_file for saga.namespace.Entry API with URL scheme(s) ['file://', 'local://', 'sftp://', 'gsisftp://', 'ssh://', 'gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.shell.shell_file for saga.filesystem.Directory API with URL scheme(s) ['file://', 'local://', 'sftp://', 'gsisftp://', 'ssh://', 'gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.shell.shell_file for saga.filesystem.File API with URL scheme(s) ['file://', 'local://', 'sftp://', 'gsisftp://', 'ssh://', 'gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.shell.shell_resource
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [WARNING ] Skipping adaptor saga.adaptors.shell.shell_resource: beta versions are disabled (v0.1.beta)
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.redis.redis_advert
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [ERROR   ] Skipping adaptor saga.adaptors.redis.redis_advert 1: module loading failed: No module named redis
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.sge.sgejob
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.sge.sgejob for saga.job.Service API with URL scheme(s) ['sge://', 'sge+ssh://', 'sge+gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.sge.sgejob for saga.job.Job API with URL scheme(s) ['sge://', 'sge+ssh://', 'sge+gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.pbs.pbsjob
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.pbs.pbsjob for saga.job.Service API with URL scheme(s) ['pbs://', 'pbs+ssh://', 'pbs+gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.pbs.pbsjob for saga.job.Job API with URL scheme(s) ['pbs://', 'pbs+ssh://', 'pbs+gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.lsf.lsfjob
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.lsf.lsfjob for saga.job.Service API with URL scheme(s) ['lsf://', 'lsf+ssh://', 'lsf+gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.lsf.lsfjob for saga.job.Job API with URL scheme(s) ['lsf://', 'lsf+ssh://', 'lsf+gsissh://']
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.irods.irods_replica
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [ERROR   ] Skipping adaptor saga.adaptors.irods.irods_replica: failed self test: Could not run iRODS/ils.  Check iRODSenvironment and certificates ('module' object has no attribute 'logger') (/home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/saga/adaptors/irods/irods_replica.py +200 (sanity_check)  :  "environment and certificates (%s)" % ex))
2014:08:05 14:47:58 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.condor.condorjob
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.condor.condorjob for saga.job.Service API with URL scheme(s) ['condor://', 'condor+ssh://', 'condor+gsissh://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.condor.condorjob for saga.job.Job API with URL scheme(s) ['condor://', 'condor+ssh://', 'condor+gsissh://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.slurm.slurm_job
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.slurm.slurm_job for saga.job.Service API with URL scheme(s) ['slurm://', 'slurm+ssh://', 'slurm+gsissh://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.slurm.slurm_job for saga.job.Job API with URL scheme(s) ['slurm://', 'slurm+ssh://', 'slurm+gsissh://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.http.http_file
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.http.http_file for saga.namespace.Entry API with URL scheme(s) ['http://', 'https://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.http.http_file for saga.filesystem.File API with URL scheme(s) ['http://', 'https://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.aws.ec2_resource
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.aws.ec2_resource for saga.Context API with URL scheme(s) ['ec2://', 'ec2_keypair://', 'openstack://', 'eucalyptus://', 'euca://', 'aws://', 'amazon://', 'http://', 'https://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.aws.ec2_resource for saga.resource.Manager API with URL scheme(s) ['ec2://', 'ec2_keypair://', 'openstack://', 'eucalyptus://', 'euca://', 'aws://', 'amazon://', 'http://', 'https://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.aws.ec2_resource for saga.resource.Compute API with URL scheme(s) ['ec2://', 'ec2_keypair://', 'openstack://', 'eucalyptus://', 'euca://', 'aws://', 'amazon://', 'http://', 'https://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Loading  adaptor saga.adaptors.loadl.loadljob
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.loadl.loadljob for saga.job.Service API with URL scheme(s) ['loadl://', 'loadl+ssh://', 'loadl+gsissh://']
2014:08:05 14:47:59 16323  MainThread   saga.Engine           : [INFO    ] Register adaptor saga.adaptors.loadl.loadljob for saga.job.Job API with URL scheme(s) ['loadl://', 'loadl+ssh://', 'loadl+gsissh://']
2014:08:05 14:47:59 16323  MainThread   saga.saga.adaptor.ssh : [INFO    ] ignore ssh key at /home/grad03/fengl/.ssh/known_hosts (no public key: /home/grad03/fengl/.ssh/known_hosts.pub)
2014:08:05 14:47:59 16323  MainThread   saga.saga.adaptor.ssh : [INFO    ] default ssh key at /home/grad03/fengl/.ssh/id_rsa
2014:08:05 14:47:59 16323  MainThread   saga.saga.adaptor.ssh : [INFO    ] ignore ssh key at /home/grad03/fengl/.ssh/authorized_keys (no public key: /home/grad03/fengl/.ssh/authorized_keys.pub)
2014:08:05 14:47:59 16323  MainThread   saga.DefaultSession   : [DEBUG   ] adding  context : {'LifeTime' : '-1', 'Type' : 'ssh', 'UserCert' : '/home/grad03/fengl/.ssh/id_rsa.pub', 'UserKey' : '/home/grad03/fengl/.ssh/id_rsa'}
2014:08:05 14:47:59 16323  MainThread   saga.ContextSSH       : [INFO    ] init SSH context for key  at '/home/grad03/fengl/.ssh/id_rsa' done
2014:08:05 14:47:59 16323  MainThread   saga.DefaultSession   : [DEBUG   ] default context [saga.adaptor.ssh    ] : {'LifeTime' : '-1', 'Type' : 'ssh', 'UserCert' : '/home/grad03/fengl/.ssh/id_rsa.pub', 'UserKey' : '/home/grad03/fengl/.ssh/id_rsa'}
2014:08:05 14:47:59 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/lrz.json
2014:08:05 14:47:59 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/das4.json
2014:08:05 14:47:59 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/localhost.json
2014:08:05 14:47:59 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/iu.json
2014:08:05 14:47:59 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/futuregrid.json
2014:08:05 14:47:59 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/xsede.json
2014:08:05 14:47:59 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/ncar.json
2014:08:05 14:47:59 radical.pilot.MainProcess: [INFO    ] Loaded resource configurations from /home/grad03/fengl/mypyenv0/local/lib/python2.7/site-packages/radical/pilot/configs/epsrc.json
2014:08:05 14:48:00 radical.pilot.MainProcess: [INFO    ] New Session created{'database_url': 'mongodb://ec2-184-72-89-141.compute-1.amazonaws.com:24242/', 'database_name': 'radicalpilot', 'last_reconnect': None, 'uid': '53e134ef4256c03fc3d7d3ba', 'created': datetime.datetime(2014, 8, 5, 19, 47, 59, 911866)}.
2014:08:05 14:48:00 16323  MainThread   saga.radical.pilot.Session: [DEBUG   ] adding  context : {'LifeTime' : '-1', 'Type' : 'ssh'}
Initializing Pilot Manager ...
2014:08:05 14:48:00 radical.pilot.MainProcess: [DEBUG   ] Worker thread (ID: Thread-1[140440737167104]) for PilotManager 53e134f04256c03fc3d7d3bb started.
2014:08:05 14:48:00 radical.pilot.PilotLauncherWorker-1: [DEBUG   ] Connected to MongoDB. Serving requests for PilotManager 53e134f04256c03fc3d7d3bb.
Submitting Compute Pilot to Pilot Manager ...
Initializing Unit Manager ...
2014:08:05 14:48:00 radical.pilot.MainProcess: [DEBUG   ] Worker thread (ID: Thread-2[140440728774400]) for UnitManager 53e134f04256c03fc3d7d3bd started.
2014:08:05 14:48:00 radical.pilot.MainProcess: [INFO    ] Loaded scheduler: DirectSubmissionScheduler.
2014:08:05 14:48:00 radical.pilot.PilotLauncherWorker-1: [INFO    ] Launching ComputePilot {u'state': u'PendingLaunch', u'commands': [], u'description': {u'project': None, u'resource': u'localhost', u'queue': None, u'sandbox': None, u'cleanup': True, u'pilot_agent_priv': None, u'memory': None, u'cores': 1, u'runtime': 5}, u'sagajobid': None, u'started': None, u'cores_per_node': None, u'output_transfer_started': None, u'finished': None, u'submitted': datetime.datetime(2014, 8, 5, 19, 48, 0, 618000), u'output_transfer_finished': None, u'sandbox': u'file://localhost/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc/', u'pilotmanager': u'53e134f04256c03fc3d7d3bb', u'unitmanager': None, u'heartbeat': None, u'wu_queue': [], u'statehistory': [{u'timestamp': datetime.datetime(2014, 8, 5, 19, 48, 0, 617000), u'state': u'PendingLaunch'}], u'input_transfer_started': None, u'_id': ObjectId('53e134f04256c03fc3d7d3bc'), u'input_transfer_finished': None, u'nodes': None, u'log': []}
2014:08:05 14:48:00 radical.pilot.PilotLauncherWorker-1: [INFO    ] Using pilot agent /home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/agent/radical-pilot-agent-multicore.py
2014:08:05 14:48:00 radical.pilot.PilotLauncherWorker-1: [INFO    ] Using bootstrapper /home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/bootstrapper/default_bootstrapper.sh
2014:08:05 14:48:00 radical.pilot.PilotLauncherWorker-1: [DEBUG   ] Creating agent sandbox 'file://localhost/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc/'.
2014:08:05 14:48:00 radical.pilot.InputFileTransferWorker-1: [DEBUG   ] Connected to MongoDB. Serving requests for UnitManager 53e134f04256c03fc3d7d3bd.
2014:08:05 14:48:00 radical.pilot.InputFileTransferWorker-2: [DEBUG   ] Connected to MongoDB. Serving requests for UnitManager 53e134f04256c03fc3d7d3bd.
2014:08:05 14:48:00 radical.pilot.OutputFileTransferWorker-2: [DEBUG   ] Connected to MongoDB. Serving requests for UnitManager 53e134f04256c03fc3d7d3bd.2014:08:05 14:48:00 radical.pilot.OutputFileTransferWorker-1: [DEBUG   ] Connected to MongoDB. Serving requests for UnitManager 53e134f04256c03fc3d7d3bd.

2014:08:05 14:48:00 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYShell init <saga.utils.pty_shell.PTYShell object at 0x29358d0>
2014:08:05 14:48:00 16333  MainThread   saga.ShellDirectory   : [INFO    ] PTY prompt pattern: [\$#%>\]]\s*$
2014:08:05 14:48:00 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] open master pty for [sh] [localhost] fengl: /usr/bin/env TERM=vt100  "/usr/local/bin/tcsh"  -i'
2014:08:05 14:48:00 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x2ae5790>
2014:08:05 14:48:00 16333  MainThread   saga.ShellDirectory   : [INFO    ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i
2014:08:05 14:48:00 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    6] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    6] [  164] (fengl@talat (/home/grad03/fengl/pilot) %  export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) %  export PS1='$' > /dev/null 2>&1 || set prompt='$'
Ambiguous output redirect.
fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] Got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) %  export PS1='$' > /dev/null 2>&1 || set prompt='$'
Ambiguous output redirect.
fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x2ae5510>
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [INFO    ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] Scheduled ComputeUnits ['53e134f04256c03fc3d7d3be', '53e134f04256c03fc3d7d3bf', '53e134f04256c03fc3d7d3c0', '53e134f04256c03fc3d7d3c1', '53e134f04256c03fc3d7d3c2', '53e134f04256c03fc3d7d3c3', '53e134f04256c03fc3d7d3c4', '53e134f04256c03fc3d7d3c5', '53e134f04256c03fc3d7d3c6', '53e134f04256c03fc3d7d3c7'] for execution on ComputePilot '53e134f04256c03fc3d7d3bc'.
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   41] (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] Got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] running command shell:         exec /bin/sh -i
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   47] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   48] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [  175] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) %  stty -echo ; unset HISTFILE ; exec /bin/sh -i\n$ )
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [  100] ( unset PROMPT_COMMAND ;  unset HISTFILE ; PS1='PROMPT-$?->'; PS2=''; export PS1 PS2 2>&1 >/dev/null\n)
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] ComputePilot '53e134f04256c03fc3d7d3bc' state changed from 'PendingLaunch' to 'Launching'.
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got new shell prompt
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] run_sync: cd /home/grad03/fengl/pilot
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   28] (cd /home/grad03/fengl/pilot\n)
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3be' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3bf' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3c0' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3c1' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3c2' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3c3' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3c4' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3c5' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3c6' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 radical.pilot.MainProcess: [INFO    ] RUN ComputeUnit '53e134f04256c03fc3d7d3c7' state changed from 'New' to 'PendingExecution'.
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] run_sync: mkdir -p '/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc' ;  cd '/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc'
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [  163] (mkdir -p '/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc' ;  cd '/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc'\n)
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] initialized directory (0)()
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYShell init <saga.utils.pty_shell.PTYShell object at 0x2ae5610>
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [INFO    ] PTY prompt pattern: [\$#%>\]]\s*$
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x2ae5690>
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [INFO    ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i
2014:08:05 14:48:01 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   41] (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] Got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] running command shell:         exec /bin/sh -i
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   47] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   48] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [  175] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) %  stty -echo ; unset HISTFILE ; exec /bin/sh -i\n$ )
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [  100] ( unset PROMPT_COMMAND ;  unset HISTFILE ; PS1='PROMPT-$?->'; PS2=''; export PS1 PS2 2>&1 >/dev/null\n)
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   10] (PROMPT-0->)
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got new shell prompt
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] run_sync: cd /home/grad03/fengl/pilot
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   28] (cd /home/grad03/fengl/pilot\n)
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   10] (PROMPT-0->)
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYShell del  <saga.utils.pty_shell.PTYShell object at 0x29358d0>
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess del  <saga.utils.pty_process.PTYProcess object at 0x2ae5510>
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYShell del  <saga.utils.pty_shell.PTYShell object at 0x2ae5610>
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess del  <saga.utils.pty_process.PTYProcess object at 0x2ae5690>
2014:08:05 14:48:02 radical.pilot.PilotLauncherWorker-1: [DEBUG   ] Copying bootstrapper 'file://localhost//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/bootstrapper/default_bootstrapper.sh' to agent sandbox (file://localhost/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc/).
2014:08:05 14:48:02 16333  MainThread   saga.ShellFile        : [INFO    ] init_instance file://localhost//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/bootstrapper/default_bootstrapper.sh
2014:08:05 14:48:02 16333  MainThread   saga.ShellFile        : [DEBUG   ] PTYShell init <saga.utils.pty_shell.PTYShell object at 0x2935510>
2014:08:05 14:48:02 16333  MainThread   saga.ShellFile        : [INFO    ] PTY prompt pattern: [\$#%>\]]\s*$
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x29355d0>
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [INFO    ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i
2014:08:05 14:48:02 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   41] (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] Got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:03 16333  MainThread   saga.ShellFile        : [DEBUG   ] running command shell:         exec /bin/sh -i
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   47] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   48] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [  175] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) %  stty -echo ; unset HISTFILE ; exec /bin/sh -i\n$ )
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [  100] ( unset PROMPT_COMMAND ;  unset HISTFILE ; PS1='PROMPT-$?->'; PS2=''; export PS1 PS2 2>&1 >/dev/null\n)
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:03 16333  MainThread   saga.ShellFile        : [DEBUG   ] got new shell prompt
2014:08:05 14:48:03 16333  MainThread   saga.ShellFile        : [DEBUG   ] run_sync: cd /home/grad03/fengl/pilot
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   28] (cd /home/grad03/fengl/pilot\n)
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:03 16333  MainThread   saga.ShellFile        : [DEBUG   ] run_sync: true; test -r '//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/bootstrapper/default_bootstrapper.sh'
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [  124] (true; test -r '//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/bootstrapper/default_bootstrapper.sh'\n)
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:03 16333  MainThread   saga.ShellFile        : [INFO    ] file initialized (0)()
2014:08:05 14:48:03 16333  MainThread   saga.ShellFile        : [DEBUG   ] PTYShell init <saga.utils.pty_shell.PTYShell object at 0x2935590>
2014:08:05 14:48:03 16333  MainThread   saga.ShellFile        : [INFO    ] PTY prompt pattern: [\$#%>\]]\s*$
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x2935b10>
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [INFO    ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   41] (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] Got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:03 16333  MainThread   saga.ShellFile        : [DEBUG   ] running command shell:         exec /bin/sh -i
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   47] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   48] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:03 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [  175] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) %  stty -echo ; unset HISTFILE ; exec /bin/sh -i\n$ )
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [  100] ( unset PROMPT_COMMAND ;  unset HISTFILE ; PS1='PROMPT-$?->'; PS2=''; export PS1 PS2 2>&1 >/dev/null\n)
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   10] (PROMPT-0->)
2014:08:05 14:48:04 16333  MainThread   saga.ShellFile        : [DEBUG   ] got new shell prompt
2014:08:05 14:48:04 16333  MainThread   saga.ShellFile        : [DEBUG   ] run_sync: cd /home/grad03/fengl/pilot
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   28] (cd /home/grad03/fengl/pilot\n)
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   10] (PROMPT-0->)
2014:08:05 14:48:04 16333  MainThread   saga.ShellFile        : [DEBUG   ] run_sync: cp  '//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/bootstrapper/default_bootstrapper.sh' '/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc'
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [  188] (cp  '//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/bootstrapper/default_bootstrapper.sh' '/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc'\n)
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:04 16333  MainThread   saga.ShellFile        : [DEBUG   ] PTYShell del  <saga.utils.pty_shell.PTYShell object at 0x2935510>
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess del  <saga.utils.pty_process.PTYProcess object at 0x29355d0>
2014:08:05 14:48:04 16333  MainThread   saga.ShellFile        : [DEBUG   ] PTYShell del  <saga.utils.pty_shell.PTYShell object at 0x2935590>
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess del  <saga.utils.pty_process.PTYProcess object at 0x2935b10>
2014:08:05 14:48:04 radical.pilot.PilotLauncherWorker-1: [DEBUG   ] Copying agent 'file://localhost//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/agent/radical-pilot-agent-multicore.py' to agent sandbox (file://localhost/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc/).
2014:08:05 14:48:04 16333  MainThread   saga.ShellFile        : [INFO    ] init_instance file://localhost//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/agent/radical-pilot-agent-multicore.py
2014:08:05 14:48:04 16333  MainThread   saga.ShellFile        : [DEBUG   ] PTYShell init <saga.utils.pty_shell.PTYShell object at 0x292fe10>
2014:08:05 14:48:04 16333  MainThread   saga.ShellFile        : [INFO    ] PTY prompt pattern: [\$#%>\]]\s*$
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x29357d0>
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [INFO    ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   41] (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] Got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:04 16333  MainThread   saga.ShellFile        : [DEBUG   ] running command shell:         exec /bin/sh -i
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   47] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   48] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:04 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [  175] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) %  stty -echo ; unset HISTFILE ; exec /bin/sh -i\n$ )
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [  100] ( unset PROMPT_COMMAND ;  unset HISTFILE ; PS1='PROMPT-$?->'; PS2=''; export PS1 PS2 2>&1 >/dev/null\n)
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:05 16333  MainThread   saga.ShellFile        : [DEBUG   ] got new shell prompt
2014:08:05 14:48:05 16333  MainThread   saga.ShellFile        : [DEBUG   ] run_sync: cd /home/grad03/fengl/pilot
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   28] (cd /home/grad03/fengl/pilot\n)
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:05 16333  MainThread   saga.ShellFile        : [DEBUG   ] run_sync: true; test -r '//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/agent/radical-pilot-agent-multicore.py'
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [  126] (true; test -r '//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/agent/radical-pilot-agent-multicore.py'\n)
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:05 16333  MainThread   saga.ShellFile        : [INFO    ] file initialized (0)()
2014:08:05 14:48:05 16333  MainThread   saga.ShellFile        : [DEBUG   ] PTYShell init <saga.utils.pty_shell.PTYShell object at 0x29355d0>
2014:08:05 14:48:05 16333  MainThread   saga.ShellFile        : [INFO    ] PTY prompt pattern: [\$#%>\]]\s*$
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x2935890>
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [INFO    ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   41] (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] Got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:05 16333  MainThread   saga.ShellFile        : [DEBUG   ] running command shell:         exec /bin/sh -i
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   47] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   48] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [  175] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) %  stty -echo ; unset HISTFILE ; exec /bin/sh -i\n$ )
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [  100] ( unset PROMPT_COMMAND ;  unset HISTFILE ; PS1='PROMPT-$?->'; PS2=''; export PS1 PS2 2>&1 >/dev/null\n)
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   10] (PROMPT-0->)
2014:08:05 14:48:05 16333  MainThread   saga.ShellFile        : [DEBUG   ] got new shell prompt
2014:08:05 14:48:05 16333  MainThread   saga.ShellFile        : [DEBUG   ] run_sync: cd /home/grad03/fengl/pilot
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   28] (cd /home/grad03/fengl/pilot\n)
2014:08:05 14:48:05 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   10] (PROMPT-0->)
2014:08:05 14:48:06 16333  MainThread   saga.ShellFile        : [DEBUG   ] run_sync: cp  '//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/agent/radical-pilot-agent-multicore.py' '/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc/radical-pilot-agent.py'
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [  213] (cp  '//home/grad03/fengl/mypyenv0/lib/python2.7/site-packages/radical/pilot/agent/radical-pilot-agent-multicore.py' '/home/grad03/fengl/radical.pilot.sandbox/pilot-53e134f04256c03fc3d7d3bc/radical-pilot-agent.py'\n)
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:06 16333  MainThread   saga.ShellFile        : [DEBUG   ] PTYShell del  <saga.utils.pty_shell.PTYShell object at 0x292fe10>
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess del  <saga.utils.pty_process.PTYProcess object at 0x29357d0>
2014:08:05 14:48:06 16333  MainThread   saga.ShellFile        : [DEBUG   ] PTYShell del  <saga.utils.pty_shell.PTYShell object at 0x29355d0>
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess del  <saga.utils.pty_process.PTYProcess object at 0x2935890>
2014:08:05 14:48:06 16333  MainThread   saga.ShellJobService  : [DEBUG   ] PTYShell init <saga.utils.pty_shell.PTYShell object at 0x24bb410>
2014:08:05 14:48:06 16333  MainThread   saga.ShellJobService  : [INFO    ] PTY prompt pattern: [\$#%>\]]\s*$
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x1ec15d0>
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [INFO    ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   41] (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] Got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:06 16333  MainThread   saga.ShellJobService  : [DEBUG   ] running command shell:         exec /bin/sh -i
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   47] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   48] ( stty -echo ; unset HISTFILE ; exec /bin/sh -i\n)
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [  175] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) %  stty -echo ; unset HISTFILE ; exec /bin/sh -i\n$ )
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [  100] ( unset PROMPT_COMMAND ;  unset HISTFILE ; PS1='PROMPT-$?->'; PS2=''; export PS1 PS2 2>&1 >/dev/null\n)
2014:08:05 14:48:06 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:07 16333  MainThread   saga.ShellJobService  : [DEBUG   ] got new shell prompt
2014:08:05 14:48:07 16333  MainThread   saga.ShellJobService  : [DEBUG   ] run_sync: cd /home/grad03/fengl/pilot
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   28] (cd /home/grad03/fengl/pilot\n)
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:07 16333  MainThread   saga.ShellJobService  : [DEBUG   ] run_sync: mkdir -p ~/.saga/adaptors/shell_job
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   36] (mkdir -p ~/.saga/adaptors/shell_job\n)
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-0->)
2014:08:05 14:48:07 16333  MainThread   saga.ShellJobService  : [DEBUG   ] run_sync: test -f .saga/adaptors/shell_job/wrapper.sh
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    7] [   44] (test -f .saga/adaptors/shell_job/wrapper.sh\n)
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    7] [   10] (PROMPT-1->)
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] PTYProcess init <saga.utils.pty_process.PTYProcess object at 0x2ae59d0>
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [INFO    ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [   51] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\n)
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [   41] (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] Got initial shell prompt (5) (fengl@talat (/home/grad03/fengl/pilot) % )
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] write: [    9] [  120] (cd ~ && "/bin/cp" -v  "/home/grad03/fengl/.saga/adaptors/shell//staging.38515728" ".saga/adaptors/shell_job/wrapper.sh"\n)
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [  121] (cd ~ && "/bin/cp" -v  "/home/grad03/fengl/.saga/adaptors/shell//staging.38515728" ".saga/adaptors/shell_job/wrapper.sh"\n)
2014:08:05 14:48:07 16333  MainThread   saga.ShellDirectory   : [DEBUG   ] read : [    9] [  385] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) % cd ~ && "/bin/cp" -v  "/home/grad03/fengl/.saga/adaptors/shell//staging.38515728" ".saga/adaptors/shell_job/wrapper.sh"\n`/home/grad03/fengl/.saga/adaptors/shell//staging.38515728' -> `.saga/adaptors/shell_job/wrapper.sh'\nfengl@talat (/home/grad03/fengl) % )
Francis-Liu commented 9 years ago 
] ( export PS1='$' > /dev/null 2>&1 || set prompt='$'\nAmbiguous output redirect.\nfengl@talat (/home/grad03/fengl/pilot) % cd ~ && "/bin/cp" -v  "/home/grad03/fengl/.saga/adaptors/shell//staging.38515728" ".saga/adaptors/shell_job/wrapper.sh"\n`/home/grad03/fengl/.saga/adaptors/shell//staging.38515728' -> `.saga/adaptors/shell_job/wrapper.sh'\nfengl@talat (/home/grad03/fengl) % )
andre-merzky commented 9 years ago

Ambiguous output redirect.

Interesting. May I ask what your login shell is? Is it bash? Can you please find out what version your shell is? Let me guess that you are using MacOS?

export PS1='$' > /dev/null 2>&1 should be POSIX -- but I have seen old bash versions on Mac before which were not POSIX compliant... Anyway, once we know what causes this, we should be able to work around it...

andre-merzky commented 9 years ago

Ah, Mark pointed out that the shell was already visible -- you seem to use tcsh. I'll do some tests with that.

Thanks!

Francis-Liu commented 9 years ago

Yes, I'm using tcsh

[mypyenv0] fengl@talat (/home/grad03/fengl/pilot) % $SHELL --version tcsh 6.17.06 (Astron) 2011-04-15 (x86_64-unknown-linux) options wide,nls,dl,al,kan,rh,nd,color,filec

I tried to run the example under bash. But since the default SHELL in our department servers is tcsh, tcsh is still called by the script:

2014:08:05 15:08:50 17152 MainThread saga.ShellDirectory : [INFO ] running: /usr/bin/env TERM=vt100 /usr/local/bin/tcsh -i

It seems I couldn't control that.

andre-merzky commented 9 years ago

Francis, we don't have much experience with tcsh. Would it be possible to get access to your account to debug this? If not, would it be possible for you to send me your .tcshrc (and whatever other init files tcch uses) to set up a similar environment locally?

Thanks!

Francis-Liu commented 9 years ago

Andrew,

You can access my account to debug that.

How would you like me to share my account? One way to do that is you can share a desktop/terminal with me so that I can ssh to my own account from the desktop/terminal you share.

Which way would you prefer.

andre-merzky commented 9 years ago

Thanks Francis! We could do that -- but I am on a rather slow line I'm afraid. But I could send you my ssh key, and you could add it to ~/.ssh/authorized_keys? Would that work for you?

Here it is:

ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEAqIrozZw23IF+yubeVl+Ew3XJZ3zR9pzE+GUHAtOoDzmFLgzy2T3voUIzBpUtFipwHr+I68BpkHdbxm2uJBQumka3UJ1MAGuSZ/nnH/F+fqa/F+9KFklyIFbGAljQf3tljIFQwDF4rqFmzMEeufJdr/LH+DpP9wpHQMquVO1qCfTddWoZSXqikejOs5LDRzdb3YBx44TLDJ+ZMYxHHUjejv2KHZaLCFrVgesy8OZDp32sFn0ZfXNALW3n+rX7Bxq+cJGvmxTNfWiWdGm6xPWgm0hUGdv5vuqNsQdXfvT2s+E6sbthYHZ2OT379/ujnV0KC7cRuBvXeMUy/GU4uJ11oQ== merzky@boskop
Francis-Liu commented 9 years ago

Yes, I already did so.

My server is talat.cs.umn.edu

Francis-Liu commented 9 years ago

my virtualenv is ~/mypyenv0

Francis-Liu commented 9 years ago

Sorry, forgot to tell you my username: fengl

Francis-Liu commented 9 years ago

FENGL

andre-merzky commented 9 years ago

Hi Francis -- sorry for the delay in followups! I got onto your machine, thanks for the access....

andre-merzky commented 9 years ago

Francis, I commited a small patch in saga-python's devel branch which seems to fix things for tcsh. Would you mind giving it a try?

You get it like this:

  # install radical.pilot as before
  # clone the saga-python repository:
    git clone https://github.com/radical-cybertools/saga-python.git
  # istall the devel branch
    cd saga-python
    git checkout devel
    pip install --upgrade .

Please let me know if that makes a difference for you. Thanks!

Francis-Liu commented 9 years ago

Andre,

Yes, the problem has gone! Good work!

Thanks a lot! Francis

andre-merzky commented 9 years ago

Phew!

Thanks again for the access! Please remove the public key :) Also, I left some files under ~/andre_merzky/ which you may want to purge.