Mailing List Archives Public Access	UW Madison Computer Sciences Department Computer Systems Lab
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Condor-users] Parallel preemption test causing immediate job evictions and inverted priorities

Date: Wed, 11 Jul 2007 16:35:46 -0600
From: "Denis Bueno" <denbuen@xxxxxxxxxx>
Subject: [Condor-users] Parallel preemption test causing immediate job evictions and inverted priorities
All,

I have a 6-machine condor pool, ut my current job submit file only requires
two vms.  I am selecting the submit/master master as the execute machine for
this job.

I am submitting [1] several parallel 2-machine jobs to tes priorities and
preemption.  As the manual states, I have enabled dedicated job preemption
as follows:

----
| STARTD_JOB_EXPRS = JobPrio
| SCHEDD_PREEMPTION_REQUIREMENTS = (My.JobPrio < Target.Jobrio)
| SCHEDD_PREEMPTION_RANK = 0.0
`----

I should note that normal, no-preemption parallel jos work fine.

To trigger this, 

  -- Submit an initial job with priority = 0.
  -- When job 1 execues, set priority = 5 and submit new job.
     The currently running job gets preempted and evicted properly, and the
higher priority job gets scheduled and (1) sometimes begins running and (2)
sometimes immediately evicts itself.  Mostly (1) happens, so
  -- Set priority = 10 and submit a third job.
     (Looking at `condor_q -long | grep Prio` shows the three JobPrio
entries properly.) This way the last job I submit is the most important and
should be run first.

The second job is correctly preempted and the third job gets scheduled but
immediately evicted as shown by several occurrences of:

,---- | 
| 014 (127.000.000) 07/11 16:15:24 Node 0executing on host: |
<134.253.202.158:55568>
| ...
| 004 (127.000.000) 07/11 16:15:24 Jb was evicted.
|    (0) Job was not checkpointed.
|         Usr 0 00:00:00, Sys 0 00:0000  -  Run Remote Usage|         Usr 0 00:00:00, Sys 0 00:00:00  -  Run Local Usage
|     0  -  Run Bytes Sent By Job
|     22372  -  Run Bytes Received By Job
| ...
| 
`----

Note the executio and eviction times are the same.  Eventually 127.0 will
finish but sometimes 126.0 (with the "middle" priority)will execute first!

The ShadowLog [2] doesn't seem to give me any indication of the cause of the
eviction, ust the fact of the eviction.  Each job is a java job which
really doesn't do much of anyting (so it's not running out of memory or
anything) -- the master and slave just print a message, sleep for 60
seconds, then print another message and exit.  (I sleep so a higher priority
job will have time to preempt the running jo.)

Any help is appreciated; if you need moreinformation, lt me know and I
will provide it.

-Denis

[1]
# *- mode: conf -*-

### Job universe & ancillary settings.
universe = parallel
machine_count = 2
#getenv = true
# Where to direct output
output = low-prio-parallel.out$(Nde)
error = low-prio-parallel.out$(Node)
log  low-prio-parallel.log

### The files we need to use.
transfer_input_files =
dist/condortest.jar,lib/runtime/java-getopt-1.0.13.jar,run_condor_parallel_
java.OS.PPC.bat,run_condor_parallel_java.WINNT51.INTEL.bat
should_tranfer_files = YES
TRANSFER_FILES = ALWAYS
when_to_ransfer_output = ON_EXIT

### Notify someone on finish of job?
Notification = always

###here should I run?
# Requirements = (OpSys == "OSX" && Arch == "PPC") \
#                || (OpSys == "WINNT51" && Arch == "INTEL")
# Rquirements = (OpSys == "WINNT51" && Arch == "INTEL")

### What to run
# eecutable = run_condor_parallel_java.$$(OpSys).$$(Arch).bat
executable= run_condor_parallel_java.OSX.PPC.bat
# executable = rn_condor_parallel_java.WINNT51.INTEL.bat

priority = 0

arguments = condor-test.jar --master=s88909.srn.sandia.gov --num-slaves1
60
queue




[2] ShadowLog contents:
7/11 16:15:01 (fd:3) (pid:27050)
*****************************************************
7/11 16:15:1 (fd:3) (pid:27050) ** condor_shadow (CONDOR_SHADOW) STARTING
UP
7/11 16:15:01 (fd:3) (pid:2050) **
/Users/Shared/app/condor/sbin/condor_shadow
7/11 1:15:01 (fd3) (pid:27050) ** $CondorVersion: 6.8.5 May 17 2007 $
7/11 16:15:01 (fd:3) (pid:27050 ** $CondorPlatform: PPC-OSX_10_4 $
7/11 16:15:01 (fd:3) (pid:27050) ** PID = 27050
7/11 16:15:01 (fd:3) (pd:27050) ** Log last touched 7/11 16:14:16
7/11 16:15:01 (fd:3) (pid:27050) ** Running as oot: Privilege switching in
effect
7/11 16:15:01 (fd:3) (pid:27050)
*****************************************************
7/11 16:15:01 (fd:3) (pid:27050) Using config source:
/Users/Shared/app/condor/etc/condor_config
7/11 1615:01 (fd:3) (pid:27050) Using local config sources:
7/11 16:15:01 (fd:3) (id:27050)    /Users/condor/condor_config.local
7/11 16:15:01 (fd:5) (pid:27050) Setting up command soket
7/11 16:15:01 (fd:5) (pid:27050) CONDOR_INHERIT: "26872
<134.253.202.158:55567> 0 14*6*0*1*<134.253.202.158:0>*0*0*0*
15*2*0*0*<134.23.202.158:0>*0* 0"
7/11 16:15:01 (fd:5) (pid:27050) Parent PID = 26872
7/11 16:15:01 (fd:5) (pid:27050) Parent Command ock =
<134.253.202.158:55567>
7/11 16:15:01 (fd:5) (pid:27050) Inheriting Command Sockets
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:1:01 (fd:5) (pid:27050) DaemonCore--> Sockets Registered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:1:01 (fd:5) (pid:27050) DaemonCore--> 0: 14 <NULL> DC Command
Handler
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:1:01 (fd:5) (id:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Sockets Registered7/11 16:15:01 (fd:) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/1 16:15:01 (fd:5) (pid:27050) DaemonCore--> 0: 14 <ULL> DC Command
Handler
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 1: 15 <NULL DC Command
Handler
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore: Command Socket at
<134.25.202.158:55995>
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/1 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Cmmands Registered
7/11 16:15:01 (fd:5) (pid27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 0000: DC_RAISESIGNALHandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HadleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 1615:01 (fd:5) (pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 0008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Signals Registered
7/11 16:15:01 (fd:5) (pid27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 1:SIGHUP handle_dc_sighup(),
Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:7050)
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Signals Registered
7/11 16:15:01 (fd:5) (pid:2705) DaemonCore--> ~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 1: SIGHUP handle_dc_sighup(),
Blocked:0 Pendng:0
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 3: SIGQUIT
handle_dc_sigquit(), Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:2050)
7/11 16:15:01 fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Signals Registered
7/11 16:1501 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore-- 1: SIGHUP handle_dc_sighup(),
Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 3: SIGQUIT
handle_dc_sigquit(), Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 15: SIGTERM
handle_dc_sigterm(), Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050)
7/11 6:15:01 (fd:5) (pid:27050) DaemonCore--> Signals Registered
7/11 16:15:01 (fd:5) (pid:27050) DemonCore--> ~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 1: SIGHUP handle_dc_sigup(),
Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 3: SIGQUIT
handle_dc_sigquit(), Blocked:0 Pending:0
7/11 1615:01 (fd:5) (pid:27050) DaemonCore--> 15: SIGTERM
handle_dc_sigterm(), Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60009: DCSERVICEWAITPIDS
HandleDC_SERVICEWAITPIDS(), Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) ancel_Signal: signal 20 not found
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Signals Rgistered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DemonCore--> 1: SIGHUP handle_dc_sighup(),
Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 3: SGQUIT
handle_dc_sigquit(), Blocked:0 Pending:0
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 15 SIGTERM
handle_dc_sigterm(), Bloced:0 Pending:0
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60009: DC_SERVICEWAITPIDS
HandleDC_SERVICEWAITPIDS(), Blocked:0 Pendin:0
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 20: SIGCHLD
HandleDC_SIGCHLD(), Blocked:0 Pending:0
7/11 16:15:01 (fd:5 (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) in DaemonCore NewTimer()
7/11 16:15:01 (fd:5) (pi:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Timers
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~
7/11 1:15:01 (fd:5) (pid:27050) DaemonCore--> id = 0, when = 1184192116,
period = 120, handler_descrip=<check_parent>
711 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) leaving DaemonCoreNewTimer, id=0
7/11 16:15:0 (fd:5) (pid:27050) in DaemonCore NewTimer()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) aemonCore--> Timers
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~
7/11 16:15:01 (fd:5) (pid:27050) Daemonore--> id = 1, when = 1184192101,
period = 0, andler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 0, when = 118419116,
period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:5) (pid:27050)
7/11 6:15:01 (fd:5) (pid:27050) leaving DaemonCore NewTimer, id=1
7/11 16:5:01 (fd:5) (pid:27050) in DaemonCore NewTimer()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Timers
7/1 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 1, when = 118419101,
period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (f:5) (pid:27050) DaemonCore--> id = 2, when = 1184192101,
perod = 300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd5) (pid:27050) DaemonCore--> id = 0, when = 118419216,
period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (d:5) (pid:27050) leaving DaemonCore NewTimer, id=2
711 16:15:01 (fd:5) (pid:27050) SEC_DEFAULT_SESSION_DURATION is undefined,
using default value of3600
7/11 16:15:01 (fd:5) (pid:27050) in DaemonCoreNewTimer()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Timer
7/11 16:15:01 (d:5) (pid:27050) DaemonCore--> ~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 1,when = 1184192101,
period = 0, handler_escrip=<dc_touch_log_file>
7/11 16:15:01 (fd:5) (pd:27050) aemonCore--> id = 2, when = 1184192101,
period = 300, handler_descrip=<check_session_cache>
/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 3, when = 1184192101,
period= 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:5) (pid:2750) DaemonCore--> id = 0, when = 1184192116,
period = 120, handler_descrip=<check_paren>
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) leaving DaemonCore NewTimer, id=3
7/11 1615:01 (fd:5) (pid:27050) in DaemonCore NewTimer()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore-> Timers
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:5) (pd:27050) DaemonCore--> id = 1, when = 1184192101,
period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 2, when = 1184192101,
period =300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 3, when = 1184192101,
period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id  4, when = 1184192101,
period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:5) (id:27050) DaemonCore--> id = 0, when = 1184192116,
period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) leaving DaemonCore NewTimer, id=4
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
711 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: DC_RCONFIG
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60008: D_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050)
7/1116:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd:5)(pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:2050) DaemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore-- 60004: DC_RECONFIG
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60008: DC_CHILDALIV
HadleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFIG_FULL
hande_reconfig()
7/11 16:15:01 fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050)
711 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd:5) (pid:2705) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (id:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HandeProcessEitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: DC_RECONFIG
handle_econfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCre--> 60007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 6008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 1615:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFIG_FULL
handle_reconfig()
7/11 16:15:01 fd:5) (pid:27050)
7/11 16:15:01 (fd:) (pid:27050)7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd:5) (pid:2750) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:0 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5)(pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HadleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: DC_RECONFIG
handl_reconig()
7/11 16:15:01 (fd:5) (pid:27050) DaemoCore--> 60007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore-->60008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 6:15:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFIG_FULL
handle_reconfig()
7/11 16:15:0 (fd:5) (pid:27050) DaemonCore--> 457: CONFIG_VAL
andle_config_val()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:0 (fd:5) (pid:27050)
7/11 16:1501 (fd:5) (pid:27050) DaemonCore--> Commands Regisered
7/11 16:15:01 (fd:) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:2750) DaemnCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) (pd:27050) DaemonCore--> 60002: DC_CONFIG_PERSIST
handle_config()
7/11 16:15:01 (fd:5)(pid:27050) DaemonCore--> 60004: DC_RECONFIG
handle_reconfig()
7/11 16:15:01 (f:5) (pid:27050) DaemonCore--> 6000: DC_CONFIG_VAL
handle_config_va()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60008: DC_CHILDALIVE
HanleChildAliveCommand
7/11 6:15:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFIG_FLL
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 457:CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:1 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:1:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) Daemonore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore-> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) pid:27050) DaemonCore--> 60002: DC_CONFIG_PERSIST
handle_cofig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60003: DC_CONFIG_RUNTIME
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCor--> 60004: DC_RECONFIG
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:2700) DaemonCore--> 60007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore-- 60008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050) DaemonCor--> 60012: DC_RECONFIG_FULL
handle_reconfig()
7/11 16:15:01 (fd:5) (pd:27050) DaemonCore--> 457: CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01(fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemoCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60002: DC_CONFIG_PERSIST
handle_onfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60003: DC_CONFIG_RUNTIME
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: C_RECONFIG
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60006: DC_OFF_FAST
handle_off_fast()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFIG_FULL
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 457: CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60002: DC_CONFIG_PERSIST
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60003: DC_CONFIG_RUNTIME
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: DC_RECONFIG
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60005: DC_OFF_GRACEFUL
handle_off_graceful()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60006: DC_OFF_FAST
handle_off_fast()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 6007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60008: D_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFI_FULL
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 457: CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60002: DC_CONFIG_PERSIST
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60003: DC_CONFIG_RUNTIME
hande_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: DC_RECONFIG
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60005: DC_OFF_GRACEFUL
handle_off_graceful()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60006: DC_OFF_FAST
handle_off_fast()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5 (pid:27050) DaemonCore--> 60008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050) DamonCore--> 60012: DC_RECONFIG_FULL
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DemonCore--> 60015: DC_OFF_PEACEFUL
handle_off_peaceful()
7/11 16:15:01 (d:5) (pid:27050) DaemonCore--> 457: CONFIG_VAL
handle_config_val()
7/11 16:5:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCre--> Commands Registered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/1 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:5:01 (fd:5) (pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:5:01 (fd:5) (pid:27050) DaemonCore--> 60002: DC_CONFIG_PERSIST
handle_cofig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60003:DC_CONFIG_RUNTIME
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: DC_RECONFIG
handle_reconfig()
7/11 16:15:01 (d:5) (pid:27050) DaemonCore--> 60005: DC_OFF_GRACEFUL
handle_off_graceful()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60006: DC_OFF_FAST
handle_off_fast()
711 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:2750) DaemonCore--> 60008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFIG_FULL
handle_rconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60015: DC_OFF_PEACEFUL
handle_off_eaceful()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60016:
DC_SET_PEACEFUL_SHUTDOWN handle_set_peaceful_shutdown()
7/11 16:15:01 (fd:5) (pid:27050) DemonCore--> 457: CONFIGVAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:1:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60002: DC_CONFIG_PERSIST
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60003: DC_COFIG_RUNTIME
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 6004: DC_RECONFIG
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaeonCore--> 60005: DC_OFF_GRACEFUL
handle_off_graceful()
7/11 16:15:01 (fd:) (pid:27050) DaemonCore--> 60006: DC_OFF_FAST
handle_off_fast()
7/11 16:1501 (fd:5) (pid:27050) DaemonCore--> 60007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 fd:5) (pid:27050) DaemonCore--> 60008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050) DaemonCor--> 60011: DC_NOP handle_nop()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFIG_FULL
hanle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60015: DC_OFF_PEACEFUL
handle_off_peaceful()
7/11 1615:01 (fd:5) (pid:27050) DaemonCore--> 60016:
DC_SET_PEACEFUL_SHUTDOWN handle_set_peaceful_shutdown()
7/1 16:15:01 (fd:5) (pid:27050) DaemonCore--> 457: CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:7050)
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registred
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemoCore--> 60000: DC_RAISESIGNAL
HandleSigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60001 DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60002: DC_CONFI_PERSIST
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60003: DC_CONFIG_RUNTIME
handle_confi()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: DC_RECONFIG
handle_reconfig()
7/1116:15:01 (fd:5) (pid:27050) DaemonCore--> 60005: DC_OFF_GRACEFUL
handle_off_graceful()
7/11 16:15:01 (fd:5 (pid:27050) DaemonCore--> 60006: DC_OFF_FAST
handle_off_fast()
7/11 16:15:01 (fd:5) (pid:27050) Daemonore--> 60007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60008: DC_CHILDALIE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60011: DC_NOP handle_nop()
7/11 16:1:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFIG_FULL
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 6013: DC_FETCH_LOG
handle_fetch_log()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60015: DC_OFF_PEACEFUL
hadle_off_peaceful()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60016:
DC_SET_PEACEFUL_SHUTDOWN handle_set_peaceful_shudown()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 457: CONFIG_VAL
handle_confg_val()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:1:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Comands Registered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleSigComman()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
7/11 16:15:01 (fd:5)(pid:27050) DaemonCore--> 60002: DC_CONFIG_PERSIST
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60003: C_CONFIG_RUNTIME
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: DC_RECONFIG
handlereconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60005: DC_OFF_GRACEFUL
handle_off_graceful()
7/11 16:1501 (fd:5) (pid:27050) DaemonCore--> 60006: DC_OFF_FAST
handle_off_fast()
7/11 16:15:01 (fd:5) (pid:27050)DaemonCore--> 60007: DC_CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 6008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60011: DC_NOPhandle_nop()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60012: DC_RECONFIG_FULL
handle_reconfig()
7/11 1615:01 (fd:5) (pid:27050) DaemonCore--> 60013: DC_FETCH_LOG
handle_fetch_log()
7/11 16:15:01 (fd:5) (pd:27050) DaemonCore--> 60014: DC_INVALIDATE_KEY
handle_invalidate_key()
7/11 16:15:01 (fd:5) (pid:27050) aemonCore--> 60015: DC_OFF_PEACEFUL
handle_off_peaceful()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 6001:
DC_SET_PEACEFUL_SHUTDOWN handle_set_peaceful_shutdown()
7/11 16:15:01 (fd:5) (pid:27050) aemonCore--> 457: CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pi:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Commands Registered
7/11 16:15:01 (fd:5) (pid:2750) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60000: DC_RAISESIGNAL
HandleigCommand()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60001: DC_PROCESSEXIT
HandleProcessExitCommand()
711 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60002: DC_CONFIG_PERSIST
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCoe--> 60003: DC_CONFIG_RUNTIME
handle_config()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60004: DC_RECONFG
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60005: DC_OFF_GRACEFUL
handle_off_graceful()
7/11 16:1:01 (fd:5) (pid:27050) DaemonCore--> 60006: DC_OFF_FAST
handle_off_fast()
7/11 1615:01 (fd:5) (pid:27050) DaemonCore--> 60007: DC_CNFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore-> 60008: DC_CHILDALIVE
HandleChildAliveCommand
7/11 16:15:01 (fd:5) (pid:2050) DaemonCore--> 60011: DC_NOP handle_nop()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCoe--> 60012: DC_RECONFIG_FULL
handle_reconfig()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore-->60013: DC_FETCH_LOG
handle_fetch_log()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60014: D_INVALIDATE_KEY
handle_invalidate_key()
7/11 16:15:01 (fd:5 (pid:27050) DaemonCore--> 60015: DC_OFF_PEACEFUL
handle_off_peaceful()
7/11 16:15:0 (fd:5) (pid:27050) DaemonCore--> 60016:
DC_SET_PEACEFUL_SHUTDOWN handle_set_peaceful_shutdown()
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 60017: DC_TIME_OFFSET
time_offset_cedar_stub
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 457 CONFIG_VAL
handle_config_val()
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) IPVERIFY: allow: *.srn.sandia.gov
7/11 16:15:01 (fd:5) (pid:27050) IPVERIFY: allow: *.srn.sandia.gov
7/11 16:15:01 (fd:5)(pid:27050) IPVERIFY: allow: *.srn.sandia.gov
7/11 16:15:01 (fd:5) (pid:27050) IPVERIFY: allow: s889069.srn.sandia.gov
7/11 16:15:01 (fd5) (pid:27050) IPVERIFY: succesfully added
s889069.srn.sandia.gov
7/11 16:15:01 (fd:5) (pid:27050) IPVERIFY: allow: s889069.srn.sandia.gov,s889069.srn.sandia.gov
7/11 16:15:01 (fd:5) (pid:27050) IPVERIFY: succesfully added
s889069.srn.sandia.gov
7/11 16:15:01 (fd:5) (pid:2700) IPVERIFY: succesfully added
s889069.srn.sandia.gov
7/11 16:15:01 (fd:5) (pid:27050) IPVERIFY: allow: s889069.srn.sandia.gov
7/11 16:15:01 (f:5) (pid:27050) IPVERIFY: succesfully added
s889069.srn.sandia.gov
7/11 16:15:01 (fd:5) (pid:27050) in DaemonCore NewTimer()
7/11 16:15:01 (fd:5) (pid:2700)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Timers
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DamonCore--> id = 1, when = 1184192101,
period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:5) (pid:2700) DaemonCore--> id = 2, when = 1184192101,
period = 300, handler_descrp=<check_session_cache>7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 3, when = 118492101,
period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore-- id = 4, when = 1184192101,
period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 0, when = 1184192116,
period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 5, when = 1184220901,
period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:2705) leaving DaemonCore NewTimer, id=5
7/11 16:15:01 (fd:5) (pid:27050) in DaemonCore NewTimer()
7/1 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> Timers
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:5) (pid:27050)DaemonCore--> id = 1, when = 1184192101,
period = 0, handler_descrip=<dc_touch_log_fie>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 2, when = 1184192101,
period = 300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 3, when = 1184192101,
period = 1801, hander_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 4, when = 1184192101,
period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 6, when = 1184192102,
period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:01 (d:5) (pid:27050) DaemonCore--> id = 0, when = 1184192116,
period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> id = 5, when = 1184220901,
period = 0, handler_descrip=<DaemonCore::RInit()>
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) leaving DaemonCore NewTimer, id=6
7/11 16:15:01 (fd:5) (pid:2750) ENABLE_SOAP_SSL is undefined, using default
value of False
7/11 16:15:01 (fd:5) (pid:27050) SHADOW_ENABLE_SOAP_SSL is undefined, using
efault value of False
7/11 16:15:01 (fd:5) (pid:27050) ENABLE_SOAP_SSL is undefined, using default
value of False
7/11 16:15:01 (fd:5) (id:27050) SHADOW_ENABLE_SOAP_SSL is undefined, using
default value of False
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) DemonCore--> Reapers Registered
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:5) (pid:27050) DaemonCore--> 1: dummy_eaper dummy_reaper
7/11 16:15:01 (fd:5) (pid:27050)
7/11 16:15:01 (fd:5) (pid:27050) Reading job ClassAd from STDIN
MyType = ""
TargetType = ""
Myype = "Job"
TargetType = "Machine"
ClusterId = 127
QDate = 1184191829
CompletionDate = 0
Owner = "denbuen"
LocalUseCpu = 0.000000
LocalSysCpu = 0.000000
RemoteUserCpu = 0.000000
RemoteSyCpu = 0.000000
ExitStats = 0
NumCkpts_RAW = 0
NumCkpts = 0
NumRestarts = 0
NumSysemHolds = 0
CommittedTime = 0
TotalSuspensions = 0
CumulativeSuspensionTime = 0
ExitBySignal = FALSE
CondorVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
CondorPlatform = "$CondorPlatform: PPC-OSX_10_4 $"
RootDir = "/"
Iwd = "/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test"
JobUniverse = 11
Cmd = 
"/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/run_condor_parallel_java.O
SX.PPC.bat"
WantIOProxy = TRUE
WantRemoteSyscalls = FALSE
WantCheckpoint = FALSE
MinHosts = 2
JobPrio = 15
User = "denbuen@xxxxxxxxxx"
NiceUser = FALSE
JobNotification = 1
WantRemoteIO = TRUE
UserLog = 
"/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/low-prio-parallel.log"
CoreSize = 0
KillSig = "SIGTERM"
Rank = 0.000000
In = "/dev/null"
TransferIn = FALSE
Out = "low-prio-parallel.out#pArAlLeLnOdE#"
StreamOut = FALSE
Err = "low-prio-parallel.out#pArAlLeLnOdE#"
StreamErr = FALSE
BufferSize = 524288
BufferBlockSize = 32768
ShouldTransferFiles = "YES"
WhenToTransferOutput = "ON_EXIT"
TransferFiles = "ONEXIT"
TransferInput = 
"dist/condor-test.jar,lib/runtime/java-getopt-1.0.13.jar,run_condor_parallel
_java.OSX.PPC.bat,run_condor_parallel_java.WINNT51.INTEL.bat"
ImageSize_RAW = 1
ImageSize = 10000
ExecutableSize_RAW = 1
ExecutableSize = 10000
DiskUsage_RAW = 210
DiskUsage = 10000
Requirements = (Arch == "PPC") && (OpSys == "OSX") && (Disk >= DiskUsage) && 
((Memory * 1024) >= ImageSize) && (HasFileTransfer)
JobLeaseDuration = 1200
PeriodicHold = FALSE
PeriodicRelease = FALSE
PeriodicRemove = FALSE
OnExitHold = FALSE
OnExitRemove = TRUE
LeaveJobInQueue = FALSE
GlobalJobId = "s889069.srn.sandia.gov#1184191829#127.0"
ProcId = 0
JobStartDate = 1184191896
OrigMaxHosts = 2
LastVacateTime = 1184192056
BytesSent = 0.000000
BytesRecvd = 1267116.000000
RemoteWallClockTime = 69.000000
LastRemoteHost = "vm1@xxxxxxxxxxxxxxxxxxxxxx"
LastPublicClaimId = "<134.253.202.158:55568>#1184191294#25#..."
LastPublicClaimIds = 
"<134.253.202.158:55568>#1184191294#25#...,<134.253.202.158:55568>#118419129
4#26#..."
JobStatus = 1
EnteredCurrentStatus = 1184192056
LastSuspensionTime = 0
MaxHosts = 2
Scheduler = "DedicatedScheduler@xxxxxxxxxxxxxxxxxxxxxx"
PublicClaimIds = 
"<134.253.202.158:55568>#1184191294#29#...,<134.253.202.158:55568>#118419129
4#30#..."
RemoteHosts = "vm1@xxxxxxxxxxxxxxxxxxxxxx,vm2@xxxxxxxxxxxxxxxxxxxxxx"
CurrentHosts = 2
PublicClaimId = "<134.253.202.158:55568>#1184191294#29#..."
LastJobLeaseRenewal = 1184192101
RemoteHost = "vm1@xxxxxxxxxxxxxxxxxxxxxx"
RemoteVirtualMachineID = 1
ShadowBday = 1184192101
JobLastStartDate = 1184192033
JobCurrentStartDate = 1184192101
JobRunCount = 4
Environment = ""
Arguments = "condor-test.jar --master=s889069.srn.sandia.gov --num-slaves=1 
60"
Args = UNDEFINED
7/11 16:15:01 (fd:5) (pid:27050) Initializing a PARALLEL shadow for job 
127.0
7/11 16:15:01 (fd:5) (pid:27050) (127.0) (27050): PRIV_CONDOR --> PRIV_USER 
at user_log.C:194
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): ENABLE_USERLOG_LOCKING is 
undefined, using default value of True
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_CONDOR 
at user_log.C:200
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): UserLog = 
/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/low-prio-parallel.log
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): SYSAPI_GET_LOADAVG is 
undefined, using default value of True
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): *** Reserved Swap = 5120
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): *** Free Swap = 1845588
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Signals 
Registered
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 
~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 1: SIGHUP 
handle_dc_sighup(), Blocked:0 Pending:0
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 3: SIGQUIT 
handle_dc_sigquit(), Blocked:0 Pending:0
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 15: SIGTERM 
handle_dc_sigterm(), Blocked:0 Pending:0
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60009: 
DC_SERVICEWAITPIDS HandleDC_SERVICEWAITPIDS(), Blocked:0 Pending:0
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 20: SIGCHLD 
HandleDC_SIGCHLD(), Blocked:0 Pending:0
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 30: SIGUSR1 
HandleJobRemoval, Blocked:0 Pending:0
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): PRIV_CONDOR --> PRIV_USER 
at baseshadow.C:166
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): *** ClassAd Dump: 
BaseShadow::baseInit() ***
MyType = ""
TargetType = ""
MyType = "Job"
TargetType = "Machine"
ClusterId = 127
QDate = 1184191829
CompletionDate = 0
Owner = "denbuen"
LocalUserCpu = 0.000000
LocalSysCpu = 0.000000
RemoteUserCpu = 0.000000
RemoteSysCpu = 0.000000
ExitStatus = 0
NumCkpts_RAW = 0
NumCkpts = 0
NumRestarts = 0
NumSystemHolds = 0
CommittedTime = 0
TotalSuspensions = 0
CumulativeSuspensionTime = 0
ExitBySignal = FALSE
CondorVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
CondorPlatform = "$CondorPlatform: PPC-OSX_10_4 $"
RootDir = "/"
Iwd = "/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test"
JobUniverse = 11
Cmd = 
"/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/run_condor_parallel_java.O
SX.PPC.bat"
WantIOProxy = TRUE
WantRemoteSyscalls = FALSE
WantCheckpoint = FALSE
MinHosts = 2
JobPrio = 15
User = "denbuen@xxxxxxxxxx"
NiceUser = FALSE
JobNotification = 1
WantRemoteIO = TRUE
UserLog = 
"/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/low-prio-parallel.log"
CoreSize = 0
KillSig = "SIGTERM"
Rank = 0.000000
In = "/dev/null"
TransferIn = FALSE
Out = "low-prio-parallel.out#pArAlLeLnOdE#"
StreamOut = FALSE
Err = "low-prio-parallel.out#pArAlLeLnOdE#"
StreamErr = FALSE
BufferSize = 524288
BufferBlockSize = 32768
ShouldTransferFiles = "YES"
WhenToTransferOutput = "ON_EXIT"
TransferFiles = "ONEXIT"
TransferInput = 
"dist/condor-test.jar,lib/runtime/java-getopt-1.0.13.jar,run_condor_parallel
_java.OSX.PPC.bat,run_condor_parallel_java.WINNT51.INTEL.bat"
ImageSize_RAW = 1
ImageSize = 10000
ExecutableSize_RAW = 1
ExecutableSize = 10000
DiskUsage_RAW = 210
DiskUsage = 10000
Requirements = (Arch == "PPC") && (OpSys == "OSX") && (Disk >= DiskUsage) && 
((Memory * 1024) >= ImageSize) && (HasFileTransfer)
JobLeaseDuration = 1200
PeriodicHold = FALSE
PeriodicRelease = FALSE
PeriodicRemove = FALSE
OnExitHold = FALSE
OnExitRemove = TRUE
LeaveJobInQueue = FALSE
GlobalJobId = "s889069.srn.sandia.gov#1184191829#127.0"
ProcId = 0
JobStartDate = 1184191896
OrigMaxHosts = 2
LastVacateTime = 1184192056
BytesSent = 0.000000
BytesRecvd = 1267116.000000
RemoteWallClockTime = 69.000000
LastRemoteHost = "vm1@xxxxxxxxxxxxxxxxxxxxxx"
LastPublicClaimId = "<134.253.202.158:55568>#1184191294#25#..."
LastPublicClaimIds = 
"<134.253.202.158:55568>#1184191294#25#...,<134.253.202.158:55568>#118419129
4#26#..."
JobStatus = 1
EnteredCurrentStatus = 1184192056
LastSuspensionTime = 0
MaxHosts = 2
Scheduler = "DedicatedScheduler@xxxxxxxxxxxxxxxxxxxxxx"
PublicClaimIds = 
"<134.253.202.158:55568>#1184191294#29#...,<134.253.202.158:55568>#118419129
4#30#..."
RemoteHosts = "vm1@xxxxxxxxxxxxxxxxxxxxxx,vm2@xxxxxxxxxxxxxxxxxxxxxx"
CurrentHosts = 2
PublicClaimId = "<134.253.202.158:55568>#1184191294#29#..."
LastJobLeaseRenewal = 1184192101
RemoteHost = "vm1@xxxxxxxxxxxxxxxxxxxxxx"
RemoteVirtualMachineID = 1
ShadowBday = 1184192101
JobLastStartDate = 1184192033
JobCurrentStartDate = 1184192101
JobRunCount = 4
Environment = ""
Arguments = "condor-test.jar --master=s889069.srn.sandia.gov --num-slaves=1 
60"
Args = UNDEFINED
MyAddress = "<134.253.202.158:55995>"
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): --- End of ClassAd ---
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Commands 
Registered
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 
~~~~~~~~~~~~~~~~~~~
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60000: 
DC_RAISESIGNAL HandleSigCommand()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60001: 
DC_PROCESSEXIT HandleProcessExitCommand()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60002: 
DC_CONFIG_PERSIST handle_config()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60003: 
DC_CONFIG_RUNTIME handle_config()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60004: 
DC_RECONFIG handle_reconfig()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60005: 
DC_OFF_GRACEFUL handle_off_graceful()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60006: 
DC_OFF_FAST handle_off_fast()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60007: 
DC_CONFIG_VAL handle_config_val()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60008: 
DC_CHILDALIVE HandleChildAliveCommand
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60011: 
DC_NOP handle_nop()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60012: 
DC_RECONFIG_FULL handle_reconfig()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60013: 
DC_FETCH_LOG handle_fetch_log()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60014: 
DC_INVALIDATE_KEY handle_invalidate_key()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60015: 
DC_OFF_PEACEFUL handle_off_peaceful()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60016: 
DC_SET_PEACEFUL_SHUTDOWN handle_set_peaceful_shutdown()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 60017: 
DC_TIME_OFFSET time_offset_cedar_stub
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 71000: 
SHADOW_UPDATEINFO ParallelShadow::updateFromStarter
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> 457: 
CONFIG_VAL handle_config_val()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Replaced $(NODE), now 
using: Out = "low-prio-parallel.out0"
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Replaced $(NODE), now 
using: Err = "low-prio-parallel.out0"
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): in 
RemoteResource::initStartdInfo()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): SHADOW_TIMEOUT_MULTIPLIER 
is undefined, using default value of 0
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): New Daemon obj (startd) 
name: "vm1@xxxxxxxxxxxxxxxxxxxxxx", pool: "NULL", addr: "NULL"
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Granting remote host 
"134.253.202.158" (<134.253.202.158:55568>)  WRITE and DAEMON permission.
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Entered 
IpVerify::AddAllowHost(134.253.202.158, WRITE)
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Adding new hostallow 
(WRITE) entry for "134.253.202.158"
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Entered 
IpVerify::AddAllowHost(134.253.202.158, DAEMON)
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): IpVerify::AddAllowHost: 
Changing mask, was 32, adding 131072)
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Added.
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): in DaemonCore NewTimer()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 1, when 
= 1184192101, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192101, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184192101, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192101, period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184192102, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 7, when 
= 1184192102, period = 0, handler_descrip=<getResources>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): leaving DaemonCore 
NewTimer, id=7
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): ENABLE_STDOUT_TESTING is 
undefined, using default value of False
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 1, when 
= 1184192101, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192101, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184192101, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192101, period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184192102, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 7, when 
= 1184192102, period = 0, handler_descrip=<getResources>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore: Calling 
handler for Timer 1 (dc_touch_log_file)
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): in DaemonCore NewTimer()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 1, when 
= 1184192101, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192101, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184192101, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192101, period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184192102, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 7, when 
= 1184192102, period = 0, handler_descrip=<getResources>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): leaving DaemonCore 
NewTimer, id=8
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): In cancel_timer(), id=1
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore: Calling 
handler for Timer 2 (check_session_cache)
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): in DaemonCore NewTimer()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): In cancel_timer(), id=2
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Renewing timer id 2 for 
300 secs
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184192101, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192101, period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184192102, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 7, when 
= 1184192102, period = 0, handler_descrip=<getResources>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): leaving DaemonCore 
NewTimer, id=2
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore: Calling 
handler for Timer 3 (handle_cookie_refresh)
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): in DaemonCore NewTimer()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): In cancel_timer(), id=3
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Renewing timer id 3 for 
1801 secs
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192101, period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184192102, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 7, when 
= 1184192102, period = 0, handler_descrip=<getResources>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): leaving DaemonCore 
NewTimer, id=3
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 0 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192101, period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184192102, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 7, when 
= 1184192102, period = 0, handler_descrip=<getResources>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore: Calling 
handler for Timer 4 (self_monitor)
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Getting monitoring info 
for pid 27050
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): in DaemonCore NewTimer()
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): In cancel_timer(), id=4
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): Renewing timer id 4 for 
240 secs
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184192102, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 7, when 
= 1184192102, period = 0, handler_descrip=<getResources>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): leaving DaemonCore 
NewTimer, id=4
7/11 16:15:01 (fd:6) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 1 
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184192102, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 7, when 
= 1184192102, period = 0, handler_descrip=<getResources>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore: Calling 
handler for Timer 6 (DaemonCore::SendAliveToParent)
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore: in 
SendAliveToParent()
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore: attempting to 
connect to '<134.253.202.158:55567>'
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_ROOT at 
sock.C:526
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): PRIV_ROOT --> PRIV_USER at 
sock.C:532
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SHADOW_TIMEOUT_MULTIPLIER 
is undefined, using default value of 0
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): New Daemon obj (any) name: 
"NULL", pool: "NULL", addr: "<134.253.202.158:55567>"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): STARTCOMMAND: starting 
60008 to <134.253.202.158:55567> on UDP port 55026.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: command 60008 to 
<134.253.202.158:55567> on UDP port 55026 (blocking).
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: no cached key for 
{<134.253.202.158:55567>,<60008>}.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: Security Policy:
MyType = ""
TargetType = ""
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: negotiating 
security for command 60008.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: need to start a 
session via TCP
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SEC_TCP_SESSION_TIMEOUT is 
undefined, using default value of 20
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: setting timeout to 
20 seconds.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_ROOT at 
sock.C:526
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): PRIV_ROOT --> PRIV_USER at 
sock.C:532
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): CONNECT 
src=<134.253.202.158:55998> fd=7 dst=<134.253.202.158:55567>
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 60010 to 
<134.253.202.158:55567> on TCP port 55998 (blocking).
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: no cached key for 
{<134.253.202.158:55567>,<60010>}.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: Security Policy:
MyType = ""
TargetType = ""
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
NewSession = "YES"
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: negotiating 
security for command 60010.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: sending 
DC_AUTHENTICATE command
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: sending following 
classad:
MyType = ""
TargetType = ""
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
NewSession = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 60010
AuthCommand = 60008
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: server responded 
with:
MyType = "(unknown type)"
TargetType = "(unknown type)"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
SessionDuration = "8640000"
Enact = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerTime = 1184192102
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: received post-auth 
classad:
MyType = "(unknown type)"
TargetType = "(unknown type)"
Sid = "s889069:26872:1184192102:32"
ValidCommands = "60000,60001,60008,71003"
ServerTime = 1184192102
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: policy to be 
cached:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 60010
AuthCommand = 60008
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26872:1184192102:32"
ValidCommands = "60000,60001,60008,71003"
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: added session 
s889069:26872:1184192102:32 to cache for 8640000 seconds.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55567>,<60000>} mapped to session 
s889069:26872:1184192102:32.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55567>,<60001>} mapped to session 
s889069:26872:1184192102:32.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55567>,<60008>} mapped to session 
s889069:26872:1184192102:32.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55567>,<71003>} mapped to session 
s889069:26872:1184192102:32.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: startCommand 
succeeded.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: sending eom() and 
closing TCP sock.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): CLOSE 
<134.253.202.158:55998> fd=7
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: succesfully sent 
NOP via TCP!
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: resuming command 
60008 to <134.253.202.158:55567> on UDP port 55026 (blocking).
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: using session 
s889069:26872:1184192102:32 for {<134.253.202.158:55567>,<60008>}.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: found cached 
session id s889069:26872:1184192102:32 for 
{<134.253.202.158:55567>,<60008>}.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SEC_DEBUG_PRINT_KEYS is 
undefined, using default value of False
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 60010
AuthCommand = 60008
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26872:1184192102:32"
ValidCommands = "60000,60001,60008,71003"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: Security Policy:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 60010
AuthCommand = 60008
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26872:1184192102:32"
ValidCommands = "60000,60001,60008,71003"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: negotiating 
security for command 60008.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: UDP, have_session 
== 1, can_neg == 1
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: UDP has session 
s889069:26872:1184192102:32.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: sending 
DC_AUTHENTICATE command
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: sending following 
classad:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
AuthCommand = 60008
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26872:1184192102:32"
ValidCommands = "60000,60001,60008,71003"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 60008
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: startCommand 
succeeded.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): DaemonCore: Sending alive 
to <134.253.202.158:55567>
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SEND [605] 
<134.253.202.158:55026> <134.253.202.158:55567>
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Destroying Daemon object:
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Type: 1 (any), Name: 
(null), Addr: <134.253.202.158:55567>
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): FullHost: (null), Host: 
(null), Pool: (null), Port: -1
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): IsLocal: N, IdStr: (null), 
Error: (null)
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050):  --- End of Daemon object 
info ---
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): in DaemonCore NewTimer()
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): In cancel_timer(), id=6
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): Renewing timer id 6 for 
1170 secs
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 7, when 
= 1184192102, period = 0, handler_descrip=<getResources>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): 
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): leaving DaemonCore 
NewTimer, id=6
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): DaemonCore: Calling 
handler for Timer 7 (getResources)
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): Getting machines from 
schedd now...
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): SHADOW_TIMEOUT_MULTIPLIER 
is undefined, using default value of 0
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): New Daemon obj (schedd) 
name: "NULL", pool: "NULL", addr: "NULL"
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): Neither name nor addr 
specified, using local values - name: "s889069.srn.sandia.gov", full host: 
"s889069.srn.sandia.gov"
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): Finding address for local 
daemon, SCHEDD_ADDRESS_FILE is "/Users/condor/log/.schedd_address"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Found valid address 
"<134.253.202.158:55567>" in local address file
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Found version string 
"$CondorVersion: 6.8.5 May 17 2007 $" in local address file
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Found platform string 
"$CondorPlatform: PPC-OSX_10_4 $" in local address file
7/11 16:15:02 (fd:6) (pid:27050) (127.0) (27050): Using port 55567 based on 
address "<134.253.202.158:55567>"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_ROOT at 
sock.C:526
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): PRIV_ROOT --> PRIV_USER at 
sock.C:532
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): CONNECT 
src=<134.253.202.158:55999> fd=6 dst=<134.253.202.158:55567>
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): STARTCOMMAND: starting 
71003 to <134.253.202.158:55567> on TCP port 55999.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): DAEMON: talking to a 
$CondorVersion: 6.8.5 May 17 2007 $ daemon.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: command 71003 to 
<134.253.202.158:55567> on TCP port 55999 (blocking).
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: using session 
s889069:26872:1184192102:32 for {<134.253.202.158:55567>,<71003>}.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: found cached 
session id s889069:26872:1184192102:32 for 
{<134.253.202.158:55567>,<71003>}.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SEC_DEBUG_PRINT_KEYS is 
undefined, using default value of False
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 60010
AuthCommand = 60008
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26872:1184192102:32"
ValidCommands = "60000,60001,60008,71003"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: Security Policy:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 60010
AuthCommand = 60008
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26872:1184192102:32"
ValidCommands = "60000,60001,60008,71003"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: negotiating 
security for command 71003.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: sending 
DC_AUTHENTICATE command
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: sending following 
classad:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
AuthCommand = 60008
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26872:1184192102:32"
ValidCommands = "60000,60001,60008,71003"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 71003
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SECMAN: startCommand 
succeeded.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Got 2 matches for proc # 0
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Got host: 
<134.253.202.158:55568> id: <134.253.202.158:55568>#1184191294#29#...
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Got host: 
<134.253.202.158:55568> id: <134.253.202.158:55568>#1184191294#30#...
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): in 
RemoteResource::initStartdInfo()
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): SHADOW_TIMEOUT_MULTIPLIER 
is undefined, using default value of 0
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): New Daemon obj (startd) 
name: "NULL", pool: "NULL", addr: "<134.253.202.158:55568>"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Granting remote host 
"134.253.202.158" (<134.253.202.158:55568>)  WRITE and DAEMON permission.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Entered 
IpVerify::AddAllowHost(134.253.202.158, WRITE)
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): IpVerify::AddAllowHost: 
Already have 134.253.202.158 with 32
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Entered 
IpVerify::AddAllowHost(134.253.202.158, DAEMON)
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): IpVerify::AddAllowHost: 
Already have 134.253.202.158 with 131072
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Replaced $(NODE), now 
using: Out = "low-prio-parallel.out1"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Replaced $(NODE), now 
using: Err = "low-prio-parallel.out1"
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): #1 - Shadow started; 2 
machines gotten.
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): In 
ParallelShadow::startMaster()
7/11 16:15:02 (fd:7) (pid:27050) (127.0) (27050): Entering 
DCStartd::activateClaim()
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_ROOT at 
sock.C:526
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): PRIV_ROOT --> PRIV_USER at 
sock.C:532
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): CONNECT 
src=<134.253.202.158:56000> fd=7 dst=<134.253.202.158:55568>
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): STARTCOMMAND: starting 444 
to <134.253.202.158:55568> on TCP port 56000.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 444 to 
<134.253.202.158:55568> on TCP port 56000 (blocking).
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: no cached key for 
{<134.253.202.158:55568>,<444>}.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: Security Policy:
MyType = ""
TargetType = ""
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
NewSession = "YES"
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: negotiating 
security for command 444.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: sending 
DC_AUTHENTICATE command
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: sending following 
classad:
MyType = ""
TargetType = ""
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
NewSession = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 444
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: server responded 
with:
MyType = "(unknown type)"
TargetType = "(unknown type)"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
SessionDuration = "8640000"
Enact = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: received post-auth 
classad:
MyType = "(unknown type)"
TargetType = "(unknown type)"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: policy to be 
cached:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 444
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: added session 
s889069:26873:1184192102:27 to cache for 8640000 seconds.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<60017>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<403>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<404>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<427>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<435>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<436>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<441>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<442>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<443>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<444>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<446>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55568>,<466>} mapped to session 
s889069:26873:1184192102:27.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): SECMAN: startCommand 
succeeded.
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): DCStartd::activateClaim: 
successfully sent command, reply is: 1
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): Request to run on 
<134.253.202.158:55568> was ACCEPTED
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): 
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): DaemonCore--> Sockets 
Registered
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): DaemonCore--> 
~~~~~~~~~~~~~~~~~~~
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): DaemonCore--> 0: 14 <NULL> 
DC Command Handler
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): DaemonCore--> 1: 15 <NULL> 
DC Command Handler
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): DaemonCore--> 2: 7 RSC 
Socket HandleSyscalls
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): 
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): Resource 
vm1@xxxxxxxxxxxxxxxxxxxxxx changing state from PRE to STARTUP
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): Just requested resource 
for node 0
7/11 16:15:02 (fd:8) (pid:27050) (127.0) (27050): Entering 
DCStartd::activateClaim()
7/11 16:15:02 (fd:9) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_ROOT at 
sock.C:526
7/11 16:15:02 (fd:9) (pid:27050) (127.0) (27050): PRIV_ROOT --> PRIV_USER at 
sock.C:532
7/11 16:15:02 (fd:9) (pid:27050) (127.0) (27050): CONNECT 
src=<134.253.202.158:56002> fd=8 dst=<134.253.202.158:55568>
7/11 16:15:02 (fd:9) (pid:27050) (127.0) (27050): STARTCOMMAND: starting 444 
to <134.253.202.158:55568> on TCP port 56002.
7/11 16:15:02 (fd:9) (pid:27050) (127.0) (27050): SECMAN: command 444 to 
<134.253.202.158:55568> on TCP port 56002 (blocking).
7/11 16:15:02 (fd:9) (pid:27050) (127.0) (27050): SECMAN: using session 
s889069:26873:1184192102:27 for {<134.253.202.158:55568>,<444>}.
7/11 16:15:02 (fd:9) (pid:27050) (127.0) (27050): SECMAN: found cached 
session id s889069:26873:1184192102:27 for {<134.253.202.158:55568>,<444>}.
7/11 16:15:02 (fd:9) (pid:27050) (127.0) (27050): SEC_DEBUG_PRINT_KEYS is 
undefined, using default value of False
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 444
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
7/11 16:15:02 (fd:9) (pid:27050) (127.0) (27050): SECMAN: Security Policy:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 444
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): SECMAN: negotiating 
security for command 444.
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): SECMAN: sending 
DC_AUTHENTICATE command
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): SECMAN: sending following 
classad:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 444
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): SECMAN: startCommand 
succeeded.
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=9
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=9
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DCStartd::activateClaim: 
successfully sent command, reply is: 1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Request to run on 
<134.253.202.158:55568> was ACCEPTED
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Sockets 
Registered
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 
~~~~~~~~~~~~~~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 0: 14 <NULL> 
DC Command Handler
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 1: 15 <NULL> 
DC Command Handler
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 2: 7 RSC 
Socket HandleSyscalls
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 3: 8 RSC 
Socket HandleSyscalls
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Resource 
<134.253.202.158:55568> changing state from PRE to STARTUP
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Just requested resource 
for node 1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Destroying Daemon object:
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Type: 3 (schedd), Name: 
s889069.srn.sandia.gov, Addr: <134.253.202.158:55567>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): FullHost: 
s889069.srn.sandia.gov, Host: s889069, Pool: (null), Port: 55567
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): IsLocal: Y, IdStr: (null), 
Error: (null)
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):  --- End of Daemon object 
info ---
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): In cancel_timer(), id=7
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 13 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Calling Handler 
<HandleSyscalls> for Socket <RSC Socket>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): About to decode 
condor_sysnum
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Got request for syscall 
get_job_info (-63)
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): entering 
FileTransfer::Init
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Commands 
Registered
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 
~~~~~~~~~~~~~~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 61000: 
FILETRANS_UPLOAD FileTransfer::HandleCommands()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60000: 
DC_RAISESIGNAL HandleSigCommand()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60001: 
DC_PROCESSEXIT HandleProcessExitCommand()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60002: 
DC_CONFIG_PERSIST handle_config()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60003: 
DC_CONFIG_RUNTIME handle_config()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60004: 
DC_RECONFIG handle_reconfig()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60005: 
DC_OFF_GRACEFUL handle_off_graceful()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60006: 
DC_OFF_FAST handle_off_fast()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60007: 
DC_CONFIG_VAL handle_config_val()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60008: 
DC_CHILDALIVE HandleChildAliveCommand
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60011: 
DC_NOP handle_nop()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60012: 
DC_RECONFIG_FULL handle_reconfig()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60013: 
DC_FETCH_LOG handle_fetch_log()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60014: 
DC_INVALIDATE_KEY handle_invalidate_key()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60015: 
DC_OFF_PEACEFUL handle_off_peaceful()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60016: 
DC_SET_PEACEFUL_SHUTDOWN handle_set_peaceful_shutdown()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60017: 
DC_TIME_OFFSET time_offset_cedar_stub
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 71000: 
SHADOW_UPDATEINFO ParallelShadow::updateFromStarter
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 457: 
CONFIG_VAL handle_config_val()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Commands 
Registered
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 
~~~~~~~~~~~~~~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 61000: 
FILETRANS_UPLOAD FileTransfer::HandleCommands()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 61001: 
FILETRANS_DOWNLOAD FileTransfer::HandleCommands()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60000: 
DC_RAISESIGNAL HandleSigCommand()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60001: 
DC_PROCESSEXIT HandleProcessExitCommand()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60002: 
DC_CONFIG_PERSIST handle_config()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60003: 
DC_CONFIG_RUNTIME handle_config()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60004: 
DC_RECONFIG handle_reconfig()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60005: 
DC_OFF_GRACEFUL handle_off_graceful()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60006: 
DC_OFF_FAST handle_off_fast()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60007: 
DC_CONFIG_VAL handle_config_val()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60008: 
DC_CHILDALIVE HandleChildAliveCommand
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60011: 
DC_NOP handle_nop()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60012: 
DC_RECONFIG_FULL handle_reconfig()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60013: 
DC_FETCH_LOG handle_fetch_log()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60014: 
DC_INVALIDATE_KEY handle_invalidate_key()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60015: 
DC_OFF_PEACEFUL handle_off_peaceful()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60016: 
DC_SET_PEACEFUL_SHUTDOWN handle_set_peaceful_shutdown()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 60017: 
DC_TIME_OFFSET time_offset_cedar_stub
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 71000: 
SHADOW_UPDATEINFO ParallelShadow::updateFromStarter
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 457: 
CONFIG_VAL handle_config_val()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Reapers 
Registered
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 
~~~~~~~~~~~~~~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 1: 
dummy_reaper dummy_reaper
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> 2: 
FileTransfer::Reaper FileTransfer::Reaper()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): entering 
FileTransfer::SimpleInit
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Entering 
FileTransfer::InitDownloadFilenameRemaps
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):     rval = 0, errno = 0
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 13 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Calling Handler 
<HandleSyscalls> for Socket <RSC Socket>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): About to decode 
condor_sysnum
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Got request for syscall 
register_starter_info (-77)
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   StarterIpAddr = 
<134.253.202.158:56001>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   UidDomain = sandia.gov
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   FileSystemDomain = 
s889069.srn.sandia.gov
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   Machine = 
vm1@xxxxxxxxxxxxxxxxxxxxxx
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   Arch = PPC
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   OpSys = OSX
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   CondorVersion = 
$CondorVersion: 6.8.5 May 17 2007 $
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   HasReconnect = TRUE
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):     rval = 0, errno = 0
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 13 
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): ACCEPT 
from=<134.253.202.158:56005> newfd=9 to=<134.253.202.158:55995>
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: received 
DC_AUTHENTICATE from <134.253.202.158:56005>
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: received 
following ClassAd:
MyType = "(unknown type)"
TargetType = "(unknown type)"
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "STARTER"
ParentUniqueID = "s889069:26873:1184191294"
ServerPid = 27051
SessionDuration = "8640000"
NewSession = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:56001>"
Command = 61000
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: 
our_policy:
MyType = ""
TargetType = ""
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: 
the_policy:
MyType = ""
TargetType = ""
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
SessionDuration = "8640000"
Enact = "YES"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): SECMAN: Sending following 
response ClassAd:
MyType = ""
TargetType = ""
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
SessionDuration = "8640000"
Enact = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: not 
authenticating.
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: sending 
session ad:
MyType = ""
TargetType = ""
Sid = "s889069:27050:1184192103:0"
ValidCommands = "61000,61001,60004"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: sent 
session s889069:27050:1184192103:0 info!
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: added 
incoming session id s889069:27050:1184192103:0 to cache for 8640000 seconds 
(return address is <134.253.202.158:56001>).
MyType = ""
TargetType = ""
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
SessionDuration = "8640000"
Enact = "YES"
Subsystem = "STARTER"
ServerCommandSock = "<134.253.202.158:56001>"
ParentUniqueID = "s889069:26873:1184191294"
ServerPid = 27051
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Sid = "s889069:27050:1184192103:0"
ValidCommands = "61000,61001,60004"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: setting 
sock->decode()
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: allowing 
an empty message for sock.
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: Success.
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DaemonCore: Command 
received via TCP from host <134.253.202.158:56005>
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DaemonCore: received 
command 61000 (FILETRANS_UPLOAD), calling handler 
(FileTransfer::HandleCommands())
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): entering 
FileTransfer::HandleCommands
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): 
FileTransfer::HandleCommands read transkey=1#469556672936582514aea2e2
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): entering 
FileTransfer::Upload
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): entering 
FileTransfer::DoUpload
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
dist/condor-test.jar
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for dist/condor-test.jar
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100644
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename 
/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/dist/condor-test.jar
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
154051
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 154051 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
154051 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
lib/runtime/java-getopt-1.0.13.jar
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for lib/runtime/java-getopt-1.0.13.jar
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100644
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename 
/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/lib/runtime/java-getopt-1.0
.13.jar
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
56709
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 56709 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
56709 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
run_condor_parallel_java.OSX.PPC.bat
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for run_condor_parallel_java.OSX.PPC.bat
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100755
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename 
/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/run_condor_parallel_java.OS
X.PPC.bat
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
168
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 168 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
168 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
run_condor_parallel_java.WINNT51.INTEL.bat
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for run_condor_parallel_java.WINNT51.INTEL.bat
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100755
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename 
/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/run_condor_parallel_java.WI
NNT51.INTEL.bat
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
90
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 90 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
90 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
/Users/condor/spool/cluster127.ickpt.subproc0
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for /Users/condor/spool/cluster127.ickpt.subproc0
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100755
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename /Users/condor/spool/cluster127.ickpt.subproc0
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
168
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 168 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
168 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: exiting at 2210
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): CLOSE 
<134.253.202.158:55995> fd=9
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 13 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Calling Handler 
<HandleSyscalls> for Socket <RSC Socket>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): About to decode 
condor_sysnum
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=9
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=9
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Got request for syscall 
get_job_info (-63)
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): entering 
FileTransfer::Init
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): entering 
FileTransfer::SimpleInit
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Entering 
FileTransfer::InitDownloadFilenameRemaps
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):     rval = 0, errno = 0
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 13 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Calling Handler 
<HandleSyscalls> for Socket <RSC Socket>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): About to decode 
condor_sysnum
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=9
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=9
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): Got request for syscall 
register_starter_info (-77)
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   StarterIpAddr = 
<134.253.202.158:56003>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   UidDomain = sandia.gov
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   FileSystemDomain = 
s889069.srn.sandia.gov
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   Machine = 
vm2@xxxxxxxxxxxxxxxxxxxxxx
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   Arch = PPC
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   OpSys = OSX
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   CondorVersion = 
$CondorVersion: 6.8.5 May 17 2007 $
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):   HasReconnect = TRUE
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050):     rval = 0, errno = 0
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 13 
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): ACCEPT 
from=<134.253.202.158:56007> newfd=9 to=<134.253.202.158:55995>
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: received 
DC_AUTHENTICATE from <134.253.202.158:56007>
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: received 
following ClassAd:
MyType = "(unknown type)"
TargetType = "(unknown type)"
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "STARTER"
ParentUniqueID = "s889069:26873:1184191294"
ServerPid = 27052
SessionDuration = "8640000"
NewSession = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:56003>"
Command = 61000
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: 
our_policy:
MyType = ""
TargetType = ""
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: 
the_policy:
MyType = ""
TargetType = ""
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
SessionDuration = "8640000"
Enact = "YES"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): SECMAN: Sending following 
response ClassAd:
MyType = ""
TargetType = ""
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
SessionDuration = "8640000"
Enact = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: not 
authenticating.
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: sending 
session ad:
MyType = ""
TargetType = ""
Sid = "s889069:27050:1184192103:1"
ValidCommands = "61000,61001,60004"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: sent 
session s889069:27050:1184192103:1 info!
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: added 
incoming session id s889069:27050:1184192103:1 to cache for 8640000 seconds 
(return address is <134.253.202.158:56003>).
MyType = ""
TargetType = ""
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
SessionDuration = "8640000"
Enact = "YES"
Subsystem = "STARTER"
ServerCommandSock = "<134.253.202.158:56003>"
ParentUniqueID = "s889069:26873:1184191294"
ServerPid = 27052
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Sid = "s889069:27050:1184192103:1"
ValidCommands = "61000,61001,60004"
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: setting 
sock->decode()
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: allowing 
an empty message for sock.
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DC_AUTHENTICATE: Success.
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DaemonCore: Command 
received via TCP from host <134.253.202.158:56007>
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): DaemonCore: received 
command 61000 (FILETRANS_UPLOAD), calling handler 
(FileTransfer::HandleCommands())
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): entering 
FileTransfer::HandleCommands
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): 
FileTransfer::HandleCommands read transkey=2#469556677d05744e7968c54e
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): entering 
FileTransfer::Upload
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): entering 
FileTransfer::DoUpload
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
dist/condor-test.jar
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for dist/condor-test.jar
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100644
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename 
/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/dist/condor-test.jar
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
154051
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 154051 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
154051 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
lib/runtime/java-getopt-1.0.13.jar
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for lib/runtime/java-getopt-1.0.13.jar
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100644
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename 
/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/lib/runtime/java-getopt-1.0
.13.jar
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
56709
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 56709 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
56709 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
run_condor_parallel_java.OSX.PPC.bat
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for run_condor_parallel_java.OSX.PPC.bat
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100755
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename 
/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/run_condor_parallel_java.OS
X.PPC.bat
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
168
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 168 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
168 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
run_condor_parallel_java.WINNT51.INTEL.bat
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for run_condor_parallel_java.WINNT51.INTEL.bat
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100755
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename 
/Volumes/snl/work/orca/ORCAmsf/trunk/condor-test/run_condor_parallel_java.WI
NNT51.INTEL.bat
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
90
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 90 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
90 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: send file 
/Users/condor/spool/cluster127.ickpt.subproc0
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): FILETRANSFER: outgoing 
file_command is 1 for /Users/condor/spool/cluster127.ickpt.subproc0
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): 
ReliSock::put_file_with_permissions(): going to send permissions 100755
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: going to send 
from filename /Users/condor/spool/cluster127.ickpt.subproc0
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: Found file size 
168
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): put_file: sending 168 
bytes
7/11 16:15:03 (fd:12) (pid:27050) (127.0) (27050): ReliSock: put_file: sent 
168 bytes
7/11 16:15:03 (fd:11) (pid:27050) (127.0) (27050): DoUpload: exiting at 2210
7/11 16:15:03 (fd:10) (pid:27050) (127.0) (27050): CLOSE 
<134.253.202.158:55995> fd=9
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:03 (fd:9) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 13 
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192116, period = 120, handler_descrip=<check_parent>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore: Calling 
handler for Timer 0 (check_parent)
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_ROOT at 
daemon_core.C:7928
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): PRIV_ROOT --> PRIV_USER at 
daemon_core.C:7949
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): in DaemonCore NewTimer()
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): In cancel_timer(), id=0
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): Renewing timer id 0 for 
120 secs
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192236, period = 120, handler_descrip=<check_parent>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): leaving DaemonCore 
NewTimer, id=0
7/11 16:15:16 (fd:9) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 45 
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Calling Handler 
<HandleSyscalls> for Socket <RSC Socket>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): About to decode 
condor_sysnum
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Got request for syscall 
begin_execution (-78)
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Resource 
vm1@xxxxxxxxxxxxxxxxxxxxxx changing state from STARTUP to EXECUTING
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050):     rval = 0, errno = 0
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): In DaemonCore Timeout()
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> Timers
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> ~~~~~~
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 8, when 
= 1184192161, period = 0, handler_descrip=<dc_touch_log_file>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 0, when 
= 1184192236, period = 120, handler_descrip=<check_parent>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 4, when 
= 1184192341, period = 240, handler_descrip=<self_monitor>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 2, when 
= 1184192401, period = 300, handler_descrip=<check_session_cache>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 6, when 
= 1184193272, period = 1170, handler_descrip=<DaemonCore::SendAliveToParent>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 3, when 
= 1184193902, period = 1801, handler_descrip=<handle_cookie_refresh>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore--> id = 5, when 
= 1184220901, period = 0, handler_descrip=<DaemonCore::ReInit()>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): 
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): DaemonCore Timeout() 
Complete, returning 37 
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Calling Handler 
<HandleSyscalls> for Socket <RSC Socket>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): About to decode 
condor_sysnum
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfds=8
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Got request for syscall 
job_exit (-65)
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): in pseudo_job_exit: 
status=15,reason=107
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Inside 
RemoteResource::updateFromStarter()
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Update ad:
MyType = "(unknown type)"
TargetType = "(unknown type)"
Node = 0
RemoteSysCpu = 0
RemoteUserCpu = 0
ImageSize = 542748
JobState = "Exited"
NumPids = 0
JobPid = 27056
JobStartDate = 1184192124
JobDuration = 0.048903
ExitBySignal = TRUE
ExitSignal = 15
ExitReason = "died on signal 15"
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): --- End of ClassAd ---
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Inside 
MpiResource::resourceExit()
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Inside 
RemoteResource::resourceExit()
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): setting exit reason on 
vm1@xxxxxxxxxxxxxxxxxxxxxx to 107
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Resource 
vm1@xxxxxxxxxxxxxxxxxxxxxx changing state from EXECUTING to FINISHED
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050):     rval = 0, errno = 0
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Shadow: do_REMOTE_syscall 
returned < 0
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): In handleJobRemoval, sig 0
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): setting exit reason on 
vm2@xxxxxxxxxxxxxxxxxxxxxx to 102
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Resource 
vm2@xxxxxxxxxxxxxxxxxxxxxx changing state from STARTUP to FINISHED
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Entering 
DCStartd::deactivateClaim(forceful)
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_ROOT 
at sock.C:526
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): PRIV_ROOT --> PRIV_USER 
at sock.C:532
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): CONNECT 
src=<134.253.202.158:56019> fd=9 dst=<134.253.202.158:55568>
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): STARTCOMMAND: starting 
404 to <134.253.202.158:55568> on TCP port 56019.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: command 404 to 
<134.253.202.158:55568> on TCP port 56019 (blocking).
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: using session 
s889069:26873:1184192102:27 for {<134.253.202.158:55568>,<404>}.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: found cached 
session id s889069:26873:1184192102:27 for {<134.253.202.158:55568>,<404>}.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SEC_DEBUG_PRINT_KEYS is 
undefined, using default value of False
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 444
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: Security Policy:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 444
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: negotiating 
security for command 404.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: sending 
DC_AUTHENTICATE command
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: sending following 
classad:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 404
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: startCommand 
succeeded.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): 
DCStartd::deactivateClaim: successfully sent command
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): CLOSE 
<134.253.202.158:56019> fd=9
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Killed starter (fast) at 
<134.253.202.158:55568>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Job 127.0 is being evicted
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Entering 
DCStartd::deactivateClaim(forceful)
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_ROOT 
at sock.C:526
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): PRIV_ROOT --> PRIV_USER 
at sock.C:532
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): CONNECT 
src=<134.253.202.158:56020> fd=9 dst=<134.253.202.158:55568>
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): STARTCOMMAND: starting 
404 to <134.253.202.158:55568> on TCP port 56020.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: command 404 to 
<134.253.202.158:55568> on TCP port 56020 (blocking).
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: using session 
s889069:26873:1184192102:27 for {<134.253.202.158:55568>,<404>}.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: found cached 
session id s889069:26873:1184192102:27 for {<134.253.202.158:55568>,<404>}.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SEC_DEBUG_PRINT_KEYS is 
undefined, using default value of False
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 444
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: Security Policy:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 444
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: negotiating 
security for command 404.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: sending 
DC_AUTHENTICATE command
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: sending following 
classad:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26873:1184192102:27"
ValidCommands = "60017,403,404,427,435,436,441,442,443,444,446,466"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 404
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: startCommand 
succeeded.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): 
DCStartd::deactivateClaim: successfully sent command
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): CLOSE 
<134.253.202.158:56020> fd=9
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Killed starter (fast) at 
<134.253.202.158:55568>
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): SHADOW_TIMEOUT_MULTIPLIER 
is undefined, using default value of 0
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): New Daemon obj (schedd) 
name: "NULL", pool: "NULL", addr: "<134.253.202.158:55569>"
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Already have address, no 
info to locate
7/11 16:15:24 (fd:9) (pid:27050) (127.0) (27050): Using port 55569 based on 
address "<134.253.202.158:55569>"
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): PRIV_USER --> PRIV_ROOT 
at sock.C:526
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): PRIV_ROOT --> PRIV_USER 
at sock.C:532
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): CONNECT 
src=<134.253.202.158:56021> fd=9 dst=<134.253.202.158:55569>
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): STARTCOMMAND: starting 
1111 to <134.253.202.158:55569> on TCP port 56021.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: command 1111 to 
<134.253.202.158:55569> on TCP port 56021 (blocking).
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: no cached key for 
{<134.253.202.158:55569>,<1111>}.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: Security Policy:
MyType = ""
TargetType = ""
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
NewSession = "YES"
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: negotiating 
security for command 1111.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: sending 
DC_AUTHENTICATE command
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: sending following 
classad:
MyType = ""
TargetType = ""
AuthMethods = "FS, ANONYMOUS, CLAIMTOBE"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
Integrity = "OPTIONAL"
Enact = "NO"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
NewSession = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 1111
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: server responded 
with:
MyType = "(unknown type)"
TargetType = "(unknown type)"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
SessionDuration = "8640000"
Enact = "YES"
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
ServerTime = 1184192124
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: received 
post-auth classad:
MyType = "(unknown type)"
TargetType = "(unknown type)"
Sid = "s889069:26872:1184192124:33"
ValidCommands = "60007,60011,1111,457,471"
ServerTime = 1184192124
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: policy to be 
cached:
MyType = ""
TargetType = ""
OutgoingNegotiation = "PREFERRED"
Subsystem = "SHADOW"
ParentUniqueID = "s889069:26872:1184191293"
ServerPid = 27050
SessionDuration = "8640000"
ServerCommandSock = "<134.253.202.158:55995>"
Command = 1111
RemoteVersion = "$CondorVersion: 6.8.5 May 17 2007 $"
Enact = "YES"
AuthMethodsList = "FS,ANONYMOUS,CLAIMTOBE"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
UseSession = "YES"
Sid = "s889069:26872:1184192124:33"
ValidCommands = "60007,60011,1111,457,471"
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: added session 
s889069:26872:1184192124:33 to cache for 8640000 seconds.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55569>,<60007>} mapped to session 
s889069:26872:1184192124:33.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55569>,<60011>} mapped to session 
s889069:26872:1184192124:33.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55569>,<1111>} mapped to session 
s889069:26872:1184192124:33.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55569>,<457>} mapped to session 
s889069:26872:1184192124:33.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: command 
{<134.253.202.158:55569>,<471>} mapped to session 
s889069:26872:1184192124:33.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): SECMAN: startCommand 
succeeded.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): AUTHENTICATE: in 
authenticate( addr == '<134.253.202.158:55569>', methods == 'FS, ANONYMOUS, 
CLAIMTOBE')
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): AUTHENTICATE: can still 
try these methods: FS, ANONYMOUS, CLAIMTOBE
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): HANDSHAKE: in 
handshake(my_methods = 'FS, ANONYMOUS, CLAIMTOBE')
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): HANDSHAKE: handshake() - 
i am the client
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): HANDSHAKE: sending 
(methods == 134) to server
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): HANDSHAKE: server replied 
(method = 4)
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): AUTHENTICATE: will try to 
use 4 (FS)
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): AUTHENTICATE_FS: used dir 
/tmp/FS_B5aKFZ67F, status: 1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): AUTHENTICATE: auth_status 
== 4 (FS)
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): Authentication was a 
Success.
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): Destroying Daemon object:
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): Type: 3 (schedd), Name: 
(null), Addr: <134.253.202.158:55569>
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): FullHost: (null), Host: 
(null), Pool: (null), Port: 55569
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): IsLocal: N, IdStr: 
(null), Error: (null)
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050):  --- End of Daemon object 
info ---
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): Updating Job Queue: 
SetAttribute(LastVacateTime = 1184192124)
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): Updating Job Queue: 
SetAttribute(BytesSent = 0.000000)
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): Updating Job Queue: 
SetAttribute(BytesRecvd = 1689488.000000)
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfds=10
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): condor_read(): nfound=1
7/11 16:15:24 (fd:10) (pid:27050) (127.0) (27050): CLOSE 
<134.253.202.158:56021> fd=9
7/11 16:15:24 (fd:3) (pid:27050) (127.0) (27050): KEYCACHEENTRY: deleted: 
0x1119840
7/11 16:15:24 (fd:3) (pid:27050) (127.0) (27050): KEYCACHEENTRY: deleted: 
0x111a8a0
7/11 16:15:24 (fd:3) (pid:27050) (127.0) (27050): KEYCACHEENTRY: deleted: 
0x111fb90
7/11 16:15:24 (fd:3) (pid:27050) (127.0) (27050): KEYCACHEENTRY: deleted: 
0x11213f0
7/11 16:15:24 (fd:3) (pid:27050) (127.0) (27050): KEYCACHEENTRY: deleted: 
0x11211f0
7/11 16:15:24 (fd:3) (pid:27050) (127.0) (27050): KEYCACHE: deleted: 
0x110bf70
7/11 16:15:24 (fd:3) (pid:27050) (127.0) (27050): CLOSE 
<134.253.202.158:55995> fd=14
7/11 16:15:24 (fd:3) (pid:27050) (127.0) (27050): **** condor_shadow 
(condor_SHADOW) EXITING WITH STATUS 107
Follow-Ups:
- Re: [Condor-users] Parallel preemption test causing immediate job evictions and inverted priorities
  - From: Denis Bueno
Prev by Date: Re: [Condor-users] running executables on other machines of cluster
Next by Date: Re: [Condor-users] Group accounting quota not working?
Previous by thread: [Condor-users] clarification on Windows credentials for condor use?
Next by thread: Re: [Condor-users] Parallel preemption test causing immediate job evictions and inverted priorities
Index(es):
- Date
- Thread
Mailing List Archives

Public Access

[Condor-users] Parallel preemption test causing immediate job evictions and inverted priorities
