Mailing List Archives
Public Access
|
|
![[Computer Systems Lab]](https://www-auth.cs.wisc.edu/pics/csl_logo.gif)
|
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Condor-users] group <none> appeared after upgrade from 7.4.3 to 7.6.2
- Date: Tue, 18 Oct 2011 15:41:53 -0500
- From: Joe Boyd <boyd@xxxxxxxx>
- Subject: [Condor-users] group <none> appeared after upgrade from 7.4.3 to 7.6.2
We have groups with dynamic quotas.
Not all jobs are submitted with an accounting group.
Attached is the NegotiatorLog for one cycle with fulldebug turned on.
In the attached log, group group_ntp has a quota of 843.433 with a usage
of 679. Group group_highprio is also under quota. When we were running
7.4, I would see that free slots would go to those groups first, and
then any slots left over would get used by the jobs that weren't
submitted with a group that had a quota.
If you search for the first "Matched" line what you'll see is that the
jobs that were submitted without a group are now apparently in the group
"<none>" and that group actually has a quota somehow (the group doesn't
actually exist so it certainly doesn't have a quota). Jobs for that
"group" get run in front of the groups that haven't filled their quota.
I do have these two things set now.
GROUP_ACCEPT_SURPLUS = False
GROUP_AUTOREGROUP = False
Am I misunderstanding how this is all supposed to work? I believe the
behavior is different from 7.4 and I certainly can't find a group
"<none>" in my old log files.
Thanks for any info,
joe
10/18/11 14:52:30 ---------- Started Negotiation Cycle ----------
10/18/11 14:52:30 Phase 1: Obtaining ads from collector ...
10/18/11 14:52:30 Getting all public ads ...
10/18/11 14:52:30 Trying to query collector <131.225.240.215:9618>
10/18/11 14:52:40 Sorting 10356 ads ...
10/18/11 14:52:40 Ignoring submitter nageshk@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter group_mcprod.shalhout@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter viviana@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter ruffini@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter lgrillo@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter ronzani@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter bward@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter fanza@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter hslee@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter whh0407@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter group_italy.ruffini@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter manoj@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter tmiao@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter seiya@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter rocio@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter tonel@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter vizan@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter rlc@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter mmp@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter hslee@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter jsw@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter manoj@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter saveliev@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter wicklund@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter feirsteo@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter tmharrin@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter vizan@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter vizan@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter shalhout@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter enidal@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter jcfree@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter oksuzian@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter loreorto@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter miyake@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter group_highprio.cdfprd_ntp@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter amanou@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter group_highprio.cdfprd_ntp@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter hwolfe@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter slava77@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter condor@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter kurata@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter csmoon@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter willis@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter sforza@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter totaro@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter wicklund@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter wicklund@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter group_dqm.cdfdqm@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter group_dqm.cdfdqm@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter group_dqm.cdfdqm@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter group_dqm.cdfdqm@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Ignoring submitter sforza@xxxxxxxx with no requested jobs
10/18/11 14:52:40 Getting startd private ads ...
10/18/11 14:52:40 Trying to query collector <131.225.240.215:9618>
10/18/11 14:52:42 Got ads: 10356 public and 10220 private
10/18/11 14:52:42 Public ads include 74 submitter, 10216 startd
10/18/11 14:52:42 Phase 2: Performing accounting ...
10/18/11 14:52:42 Entering compute_significant_attrs()
10/18/11 14:52:44 Leaving compute_significant_attrs() - result=JobUniverse,LastCheckpointPlatform,NumCkpts,x509userproxysubject,GLIDEIN_Is_Monitor,JOB_Is_Monitor,CAFDH,CAFDoNotDrain,CAFGroup
10/18/11 14:52:47 Trimmed out 5086 startd ads not Unclaimed
10/18/11 14:52:47 group quotas: assigning 74 submitters to accounting groups
10/18/11 14:52:47 group quotas: assigning group quotas from 10216 available weighted slots
10/18/11 14:52:47 group quotas: subtree <none> receiving quota= 10216
10/18/11 14:52:47 group quotas: group <none>, allocated 0 for static children, 10216 for dynamic children
10/18/11 14:52:47 group quotas: subtree group_alignment receiving quota= 102.16
10/18/11 14:52:47 group quotas: group group_alignment, allocated 0 for static children, 102.16 for dynamic children
10/18/11 14:52:47 group quotas: group group_alignment assigned quota= 102.16
10/18/11 14:52:47 group quotas: subtree group_btagging receiving quota= 204.32
10/18/11 14:52:47 group quotas: group group_btagging, allocated 0 for static children, 204.32 for dynamic children
10/18/11 14:52:47 group quotas: group group_btagging assigned quota= 204.32
10/18/11 14:52:47 group quotas: subtree group_calib receiving quota= 214.536
10/18/11 14:52:47 group quotas: group group_calib, allocated 0 for static children, 214.536 for dynamic children
10/18/11 14:52:47 group quotas: group group_calib assigned quota= 214.536
10/18/11 14:52:47 group quotas: subtree group_dbg receiving quota= 51.08
10/18/11 14:52:47 group quotas: group group_dbg, allocated 0 for static children, 51.08 for dynamic children
10/18/11 14:52:47 group quotas: group group_dbg assigned quota= 51.08
10/18/11 14:52:47 group quotas: subtree group_dqm receiving quota= 51.08
10/18/11 14:52:47 group quotas: group group_dqm, allocated 0 for static children, 51.08 for dynamic children
10/18/11 14:52:47 group quotas: group group_dqm assigned quota= 51.08
10/18/11 14:52:47 group quotas: subtree group_fixedwntest receiving quota= 51.08
10/18/11 14:52:47 group quotas: group group_fixedwntest, allocated 0 for static children, 51.08 for dynamic children
10/18/11 14:52:47 group quotas: group group_fixedwntest assigned quota= 51.08
10/18/11 14:52:47 group quotas: subtree group_florida receiving quota= 20.432
10/18/11 14:52:47 group quotas: group group_florida, allocated 0 for static children, 20.432 for dynamic children
10/18/11 14:52:47 group quotas: group group_florida assigned quota= 20.432
10/18/11 14:52:47 group quotas: subtree group_fnal receiving quota= 214.536
10/18/11 14:52:47 group quotas: group group_fnal, allocated 0 for static children, 214.536 for dynamic children
10/18/11 14:52:47 group quotas: group group_fnal assigned quota= 214.536
10/18/11 14:52:47 group quotas: subtree group_highprio receiving quota= 817.28
10/18/11 14:52:47 group quotas: group group_highprio, allocated 0 for static children, 817.28 for dynamic children
10/18/11 14:52:47 group quotas: group group_highprio assigned quota= 817.28
10/18/11 14:52:47 group quotas: subtree group_italy receiving quota= 173.672
10/18/11 14:52:47 group quotas: group group_italy, allocated 0 for static children, 173.672 for dynamic children
10/18/11 14:52:47 group quotas: group group_italy assigned quota= 173.672
10/18/11 14:52:47 group quotas: subtree group_japan receiving quota= 214.536
10/18/11 14:52:47 group quotas: group group_japan, allocated 0 for static children, 214.536 for dynamic children
10/18/11 14:52:47 group quotas: group group_japan assigned quota= 214.536
10/18/11 14:52:47 group quotas: subtree group_karlsruhe receiving quota= 51.08
10/18/11 14:52:47 group quotas: group group_karlsruhe, allocated 0 for static children, 51.08 for dynamic children
10/18/11 14:52:47 group quotas: group group_karlsruhe assigned quota= 51.08
10/18/11 14:52:47 group quotas: subtree group_mcprod receiving quota= 478.722
10/18/11 14:52:47 group quotas: group group_mcprod, allocated 0 for static children, 478.722 for dynamic children
10/18/11 14:52:47 group quotas: group group_mcprod assigned quota= 478.722
10/18/11 14:52:47 group quotas: subtree group_mit receiving quota= 30.648
10/18/11 14:52:47 group quotas: group group_mit, allocated 0 for static children, 30.648 for dynamic children
10/18/11 14:52:47 group quotas: group group_mit assigned quota= 30.648
10/18/11 14:52:47 group quotas: subtree group_ntp receiving quota= 843.433
10/18/11 14:52:47 group quotas: group group_ntp, allocated 0 for static children, 843.433 for dynamic children
10/18/11 14:52:47 group quotas: group group_ntp assigned quota= 843.433
10/18/11 14:52:47 group quotas: subtree group_physmon receiving quota= 10.216
10/18/11 14:52:47 group quotas: group group_physmon, allocated 0 for static children, 10.216 for dynamic children
10/18/11 14:52:47 group quotas: group group_physmon assigned quota= 10.216
10/18/11 14:52:47 group quotas: subtree group_prd receiving quota= 749.752
10/18/11 14:52:47 group quotas: group group_prd, allocated 0 for static children, 749.752 for dynamic children
10/18/11 14:52:47 group quotas: group group_prd assigned quota= 749.752
10/18/11 14:52:47 group quotas: subtree group_sam receiving quota= 255.4
10/18/11 14:52:47 group quotas: group group_sam, allocated 0 for static children, 255.4 for dynamic children
10/18/11 14:52:47 group quotas: group group_sam assigned quota= 255.4
10/18/11 14:52:47 group quotas: group <none> assigned quota= 5682.04
10/18/11 14:52:47 group quotas: group= <none> cquota= 0 static= 0 accept= 1 quota= 5682.04 req= 2742 usage= 2167
10/18/11 14:52:47 group quotas: group= group_alignment cquota= 0.01 static= 0 accept= 0 quota= 102.16 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_btagging cquota= 0.02 static= 0 accept= 0 quota= 204.32 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_calib cquota= 0.021 static= 0 accept= 0 quota= 214.536 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_dbg cquota= 0.005 static= 0 accept= 0 quota= 51.08 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_dqm cquota= 0.005 static= 0 accept= 0 quota= 51.08 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_fixedwntest cquota= 0.005 static= 0 accept= 0 quota= 51.08 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_florida cquota= 0.002 static= 0 accept= 0 quota= 20.432 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_fnal cquota= 0.021 static= 0 accept= 0 quota= 214.536 req= 4 usage= 1
10/18/11 14:52:47 group quotas: group= group_highprio cquota= 0.08 static= 0 accept= 0 quota= 817.28 req= 601 usage= 495
10/18/11 14:52:47 group quotas: group= group_italy cquota= 0.017 static= 0 accept= 0 quota= 173.672 req= 13102 usage= 790
10/18/11 14:52:47 group quotas: group= group_japan cquota= 0.021 static= 0 accept= 0 quota= 214.536 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_karlsruhe cquota= 0.005 static= 0 accept= 0 quota= 51.08 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_mcprod cquota= 0.04686 static= 0 accept= 0 quota= 478.722 req= 3 usage= 2
10/18/11 14:52:47 group quotas: group= group_mit cquota= 0.003 static= 0 accept= 0 quota= 30.648 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_ntp cquota= 0.08256 static= 0 accept= 0 quota= 843.433 req= 1439 usage= 679
10/18/11 14:52:47 group quotas: group= group_physmon cquota= 0.001 static= 0 accept= 0 quota= 10.216 req= 0 usage= 0
10/18/11 14:52:47 group quotas: group= group_prd cquota= 0.07339 static= 0 accept= 0 quota= 749.752 req= 2902 usage= 952
10/18/11 14:52:47 group quotas: group= group_sam cquota= 0.025 static= 0 accept= 0 quota= 255.4 req= 0 usage= 0
10/18/11 14:52:47 group quotas: allocation round 1
10/18/11 14:52:47 group quotas: fairshare (1): group= <none> quota= 5682.04 requested= 2742
10/18/11 14:52:47 group quotas: fairshare (2): group= <none> quota= 5682.04 allocated= 2742 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_alignment quota= 102.16 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_alignment quota= 102.16 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_btagging quota= 204.32 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_btagging quota= 204.32 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_calib quota= 214.536 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_calib quota= 214.536 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_dbg quota= 51.08 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_dbg quota= 51.08 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_dqm quota= 51.08 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_dqm quota= 51.08 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_fixedwntest quota= 51.08 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_fixedwntest quota= 51.08 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_florida quota= 20.432 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_florida quota= 20.432 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_fnal quota= 214.536 requested= 4
10/18/11 14:52:47 group quotas: fairshare (2): group= group_fnal quota= 214.536 allocated= 4 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_highprio quota= 817.28 requested= 601
10/18/11 14:52:47 group quotas: fairshare (2): group= group_highprio quota= 817.28 allocated= 601 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_italy quota= 173.672 requested= 13102
10/18/11 14:52:47 group quotas: fairshare (2): group= group_italy quota= 173.672 allocated= 173.672 requested= 12928.3
10/18/11 14:52:47 group quotas: fairshare (1): group= group_japan quota= 214.536 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_japan quota= 214.536 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_karlsruhe quota= 51.08 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_karlsruhe quota= 51.08 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_mcprod quota= 478.722 requested= 3
10/18/11 14:52:47 group quotas: fairshare (2): group= group_mcprod quota= 478.722 allocated= 3 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_mit quota= 30.648 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_mit quota= 30.648 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_ntp quota= 843.433 requested= 1439
10/18/11 14:52:47 group quotas: fairshare (2): group= group_ntp quota= 843.433 allocated= 843.433 requested= 595.567
10/18/11 14:52:47 group quotas: fairshare (1): group= group_physmon quota= 10.216 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_physmon quota= 10.216 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: fairshare (1): group= group_prd quota= 749.752 requested= 2902
10/18/11 14:52:47 group quotas: fairshare (2): group= group_prd quota= 749.752 allocated= 749.752 requested= 2152.25
10/18/11 14:52:47 group quotas: fairshare (1): group= group_sam quota= 255.4 requested= 0
10/18/11 14:52:47 group quotas: fairshare (2): group= group_sam quota= 255.4 allocated= 0 requested= 0
10/18/11 14:52:47 group quotas: allocate-surplus (1): group= <none> surplus= 5099.14 subtree-requested= 0
10/18/11 14:52:47 group quotas: fairshare (3): group= <none> surplus= 5099.14 subtree_requested= 0
10/18/11 14:52:47 group quotas: group= <none> quota= 5682.04 requested= 2742 allocated= 2742 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_alignment quota= 102.16 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_btagging quota= 204.32 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_calib quota= 214.536 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_dbg quota= 51.08 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_dqm quota= 51.08 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_fixedwntest quota= 51.08 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_florida quota= 20.432 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_fnal quota= 214.536 requested= 4 allocated= 4 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_highprio quota= 817.28 requested= 601 allocated= 601 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_italy quota= 173.672 requested= 13102 allocated= 173.672 unallocated= 12928.3
10/18/11 14:52:47 group quotas: group= group_japan quota= 214.536 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_karlsruhe quota= 51.08 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_mcprod quota= 478.722 requested= 3 allocated= 3 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_mit quota= 30.648 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_ntp quota= 843.433 requested= 1439 allocated= 843.433 unallocated= 595.567
10/18/11 14:52:47 group quotas: group= group_physmon quota= 10.216 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: group= group_prd quota= 749.752 requested= 2902 allocated= 749.752 unallocated= 2152.25
10/18/11 14:52:47 group quotas: group= group_sam quota= 255.4 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:47 group quotas: groups= 19 requesting= 7 served= 7 unserved= 0 slots= 10216 requested= 20793 allocated= 5116.86 surplus= 5099.14
10/18/11 14:52:47 group quotas: entering RR iteration n= 575
10/18/11 14:52:47 Group group_fnal - starvation= 0.25 (1/4) prio= 553.439
10/18/11 14:52:47 Group group_fnal - BEGIN NEGOTIATION
10/18/11 14:52:47 Phase 3: Sorting submitter ads by priority ...
10/18/11 14:52:47 Ignoring submitter group_fnal.tjyang@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter group_fnal.tonel@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Phase 4.1: Negotiating with schedds ...
10/18/11 14:52:47 numSlots = 4
10/18/11 14:52:47 slotWeightTotal = 4.000000
10/18/11 14:52:47 pieLeft = 0.000
10/18/11 14:52:47 NormalFactor = 0.000000
10/18/11 14:52:47 MaxPrioValue = 0.000000
10/18/11 14:52:47 NumSubmitterAds = 0
10/18/11 14:52:47 resources used scheddUsed= 0.000000
10/18/11 14:52:47 negotiateWithGroup resources used scheddAds length 0
10/18/11 14:52:47 Group group_mcprod - starvation= 0.666667 (2/3) prio= 183878
10/18/11 14:52:47 Group group_mcprod - BEGIN NEGOTIATION
10/18/11 14:52:47 Phase 3: Sorting submitter ads by priority ...
10/18/11 14:52:47 Ignoring submitter group_mcprod.dmietl@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter group_mcprod.shalhout@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Phase 4.1: Negotiating with schedds ...
10/18/11 14:52:47 numSlots = 3
10/18/11 14:52:47 slotWeightTotal = 3.000000
10/18/11 14:52:47 pieLeft = 0.000
10/18/11 14:52:47 NormalFactor = 0.000000
10/18/11 14:52:47 MaxPrioValue = 0.000000
10/18/11 14:52:47 NumSubmitterAds = 0
10/18/11 14:52:47 resources used scheddUsed= 0.000000
10/18/11 14:52:47 negotiateWithGroup resources used scheddAds length 0
10/18/11 14:52:47 Group <none> - starvation= 0.790299 (2167/2742) prio= 2.01015e+07
10/18/11 14:52:47 Group <none> - BEGIN NEGOTIATION
10/18/11 14:52:47 Phase 3: Sorting submitter ads by priority ...
10/18/11 14:52:47 Ignoring submitter willis@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter willis@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter vizan@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter ronzani@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter ronzani@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter samantha@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter oksuzian@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter rocio@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter rocio@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter rocio@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter enidal@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter amanou@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter amanou@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter amanou@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter amanou@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter csmoon@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter csmoon@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter loreorto@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter loreorto@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter saveliev@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter saveliev@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter saveliev@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter saveliev@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter hwolfe@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter slava77@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter wicklund@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter seiya@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter seiya@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter bward@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter jsw@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter jsw@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter nageshk@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter nageshk@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter tmharrin@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter tmharrin@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter tmharrin@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter miyake@xxxxxxxx with no idle jobs
10/18/11 14:52:47 Ignoring submitter kurata@xxxxxxxx with no idle jobs
10/18/11 14:52:47 maxAllowed = 575.000000 groupQuota = 2742.000000 groupusage = 2167.000000
10/18/11 14:52:47 Phase 4.1: Negotiating with schedds ...
10/18/11 14:52:47 numSlots = 2742
10/18/11 14:52:47 slotWeightTotal = 2742.000000
10/18/11 14:52:47 pieLeft = 575.000
10/18/11 14:52:47 NormalFactor = 1450.086887
10/18/11 14:52:47 MaxPrioValue = 14393.334961
10/18/11 14:52:47 NumSubmitterAds = 6
10/18/11 14:52:47 Negotiating with jcfree@xxxxxxxx at <131.225.240.215:50394>
10/18/11 14:52:47 0 seconds so far
10/18/11 14:52:47 maxAllowed = 575.000000 groupQuota = 2742.000000 groupusage = 2167.000000
10/18/11 14:52:47 Calculating submitter limit with the following parameters
10/18/11 14:52:47 SubmitterPrio = 10.000000
10/18/11 14:52:47 SubmitterPrioFactor = 20.000000
10/18/11 14:52:47 submitterShare = 0.992584
10/18/11 14:52:47 submitterAbsShare = 0.333333
10/18/11 14:52:47 submitterLimit = 575.000000
10/18/11 14:52:47 submitterUsage = 0.000000
10/18/11 14:52:47 Socket to jcfree@xxxxxxxx (<131.225.240.215:50394>) already in cache, reusing
10/18/11 14:52:47 Sending SEND_JOB_INFO/eom
10/18/11 14:52:47 Getting reply from schedd ...
10/18/11 14:52:47 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:47 Request 1412520.00000:
10/18/11 14:52:47 matchmakingAlgorithm: limit 575.000000 used 0.000000 pieLeft 575.000000
10/18/11 14:52:47 Concurrency Limit: total_dh_jobs is 1921.000000
10/18/11 14:52:47 Start of sorting MatchList (len=22)
10/18/11 14:52:47 Finished sorting MatchList
10/18/11 14:52:47 Connecting to startd glidein_20398@xxxxxxxxxxxxxxxxxxxx at <131.225.210.9:40041>
10/18/11 14:52:47 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:47 Matched 1412520.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.210.9:40041> glidein_20398@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Notifying the accountant
10/18/11 14:52:47 Successfully matched with glidein_20398@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Sending SEND_JOB_INFO/eom
10/18/11 14:52:47 Getting reply from schedd ...
10/18/11 14:52:47 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:47 Request 1412521.00000:
10/18/11 14:52:47 matchmakingAlgorithm: limit 575.000000 used 1.000000 pieLeft 574.000000
10/18/11 14:52:47 Concurrency Limit: total_dh_jobs is 1922.000000
10/18/11 14:52:47 Attempting to use cached MatchList: Succeeded. (MatchList length: 20, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:47 Connecting to startd glidein_32471@xxxxxxxxxxxxxxxxxxxx at <131.225.213.8:50722>
10/18/11 14:52:47 Sending MATCH_INFO/claim id to glidein_32471@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 (Claim ID is "<131.225.213.8:50722>#1318966085#3#..." )
10/18/11 14:52:47 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:47 Matched 1412521.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.213.8:50722> glidein_32471@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Notifying the accountant
10/18/11 14:52:47 Successfully matched with glidein_32471@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Sending SEND_JOB_INFO/eom
10/18/11 14:52:47 Getting reply from schedd ...
10/18/11 14:52:47 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:47 Request 1412522.00000:
10/18/11 14:52:47 matchmakingAlgorithm: limit 575.000000 used 2.000000 pieLeft 573.000000
10/18/11 14:52:47 Concurrency Limit: total_dh_jobs is 1923.000000
10/18/11 14:52:47 Attempting to use cached MatchList: Succeeded. (MatchList length: 19, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:47 Connecting to startd glidein_7690@xxxxxxxxxxxxxxxxxxxx at <131.225.208.58:43101>
10/18/11 14:52:47 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:47 Matched 1412522.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.208.58:43101> glidein_7690@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Notifying the accountant
10/18/11 14:52:47 Successfully matched with glidein_7690@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Sending SEND_JOB_INFO/eom
10/18/11 14:52:47 Getting reply from schedd ...
10/18/11 14:52:47 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:47 Request 1412523.00000:
10/18/11 14:52:47 matchmakingAlgorithm: limit 575.000000 used 3.000000 pieLeft 572.000000
10/18/11 14:52:47 Concurrency Limit: total_dh_jobs is 1924.000000
10/18/11 14:52:47 Attempting to use cached MatchList: Succeeded. (MatchList length: 18, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:47 Connecting to startd glidein_15395@xxxxxxxxxxxxxxxxxxxx at <131.225.208.20:54271>
10/18/11 14:52:47 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:47 Matched 1412523.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.208.20:54271> glidein_15395@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Notifying the accountant
10/18/11 14:52:47 Successfully matched with glidein_15395@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Sending SEND_JOB_INFO/eom
10/18/11 14:52:47 Getting reply from schedd ...
10/18/11 14:52:47 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:47 Request 1412524.00000:
10/18/11 14:52:47 matchmakingAlgorithm: limit 575.000000 used 4.000000 pieLeft 571.000000
10/18/11 14:52:47 Concurrency Limit: total_dh_jobs is 1925.000000
10/18/11 14:52:47 Attempting to use cached MatchList: Succeeded. (MatchList length: 17, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:47 Connecting to startd glidein_14963@xxxxxxxxxxxxxxxxxxxx at <131.225.210.90:47467>
10/18/11 14:52:47 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:47 Matched 1412524.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.210.90:47467> glidein_14963@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Notifying the accountant
10/18/11 14:52:47 Successfully matched with glidein_14963@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Sending SEND_JOB_INFO/eom
10/18/11 14:52:47 Getting reply from schedd ...
10/18/11 14:52:47 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:47 Request 1412525.00000:
10/18/11 14:52:47 matchmakingAlgorithm: limit 575.000000 used 5.000000 pieLeft 570.000000
10/18/11 14:52:47 Concurrency Limit: total_dh_jobs is 1926.000000
10/18/11 14:52:47 Attempting to use cached MatchList: Succeeded. (MatchList length: 16, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:47 Connecting to startd glidein_9648@xxxxxxxxxxxxxxxxxxxx at <131.225.208.180:57261>
10/18/11 14:52:47 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:47 Matched 1412525.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.208.180:57261> glidein_9648@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Notifying the accountant
10/18/11 14:52:47 Successfully matched with glidein_9648@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Sending SEND_JOB_INFO/eom
10/18/11 14:52:47 Getting reply from schedd ...
10/18/11 14:52:47 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:47 Request 1412526.00000:
10/18/11 14:52:47 matchmakingAlgorithm: limit 575.000000 used 6.000000 pieLeft 569.000000
10/18/11 14:52:47 Concurrency Limit: total_dh_jobs is 1927.000000
10/18/11 14:52:47 Attempting to use cached MatchList: Succeeded. (MatchList length: 15, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:47 Connecting to startd glidein_11625@xxxxxxxxxxxxxxxxxxxx at <131.225.208.66:34485>
10/18/11 14:52:47 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:47 Matched 1412526.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.208.66:34485> glidein_11625@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Notifying the accountant
10/18/11 14:52:47 Successfully matched with glidein_11625@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Sending SEND_JOB_INFO/eom
10/18/11 14:52:47 Getting reply from schedd ...
10/18/11 14:52:47 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:47 Request 1412527.00000:
10/18/11 14:52:47 matchmakingAlgorithm: limit 575.000000 used 7.000000 pieLeft 568.000000
10/18/11 14:52:47 Concurrency Limit: total_dh_jobs is 1928.000000
10/18/11 14:52:47 Attempting to use cached MatchList: Succeeded. (MatchList length: 14, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:47 Connecting to startd glidein_18201@xxxxxxxxxxxxxxxxxxxx at <131.225.238.93:42013>
10/18/11 14:52:47 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:47 Matched 1412527.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.238.93:42013> glidein_18201@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:47 Notifying the accountant
10/18/11 14:52:48 Successfully matched with glidein_18201@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Sending SEND_JOB_INFO/eom
10/18/11 14:52:48 Getting reply from schedd ...
10/18/11 14:52:48 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:48 Request 1412528.00000:
10/18/11 14:52:48 matchmakingAlgorithm: limit 575.000000 used 8.000000 pieLeft 567.000000
10/18/11 14:52:48 Concurrency Limit: total_dh_jobs is 1929.000000
10/18/11 14:52:48 Attempting to use cached MatchList: Succeeded. (MatchList length: 13, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:48 Connecting to startd glidein_28759@xxxxxxxxxxxxxxxxxxxx at <131.225.238.42:34549>
10/18/11 14:52:48 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:48 Matched 1412528.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.238.42:34549> glidein_28759@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Notifying the accountant
10/18/11 14:52:48 Successfully matched with glidein_28759@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Sending SEND_JOB_INFO/eom
10/18/11 14:52:48 Getting reply from schedd ...
10/18/11 14:52:48 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:48 Request 1412529.00000:
10/18/11 14:52:48 matchmakingAlgorithm: limit 575.000000 used 9.000000 pieLeft 566.000000
10/18/11 14:52:48 Concurrency Limit: total_dh_jobs is 1930.000000
10/18/11 14:52:48 Attempting to use cached MatchList: Succeeded. (MatchList length: 12, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:48 Connecting to startd glidein_30323@xxxxxxxxxxxxxxxxxxxx at <131.225.210.212:58745>
10/18/11 14:52:48 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:48 Matched 1412529.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.210.212:58745> glidein_30323@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Notifying the accountant
10/18/11 14:52:48 Successfully matched with glidein_30323@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Sending SEND_JOB_INFO/eom
10/18/11 14:52:48 Getting reply from schedd ...
10/18/11 14:52:48 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:48 Request 1412530.00000:
10/18/11 14:52:48 matchmakingAlgorithm: limit 575.000000 used 10.000000 pieLeft 565.000000
10/18/11 14:52:48 Concurrency Limit: total_dh_jobs is 1931.000000
10/18/11 14:52:48 Attempting to use cached MatchList: Succeeded. (MatchList length: 11, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:48 Connecting to startd glidein_10447@xxxxxxxxxxxxxxxxxxxx at <131.225.210.225:44195>
10/18/11 14:52:48 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:48 Matched 1412530.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.210.225:44195> glidein_10447@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Notifying the accountant
10/18/11 14:52:48 Successfully matched with glidein_10447@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Sending SEND_JOB_INFO/eom
10/18/11 14:52:48 Getting reply from schedd ...
10/18/11 14:52:48 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:48 Request 1412531.00000:
10/18/11 14:52:48 matchmakingAlgorithm: limit 575.000000 used 11.000000 pieLeft 564.000000
10/18/11 14:52:48 Concurrency Limit: total_dh_jobs is 1932.000000
10/18/11 14:52:48 Attempting to use cached MatchList: Succeeded. (MatchList length: 10, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:48 Connecting to startd glidein_11970@xxxxxxxxxxxxxxxxxxxx at <131.225.213.165:46929>
10/18/11 14:52:48 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:48 Matched 1412531.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.213.165:46929> glidein_11970@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Notifying the accountant
10/18/11 14:52:48 Successfully matched with glidein_11970@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Sending SEND_JOB_INFO/eom
10/18/11 14:52:48 Getting reply from schedd ...
10/18/11 14:52:48 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:48 Request 1412532.00000:
10/18/11 14:52:48 matchmakingAlgorithm: limit 575.000000 used 12.000000 pieLeft 563.000000
10/18/11 14:52:48 Concurrency Limit: total_dh_jobs is 1933.000000
10/18/11 14:52:48 Attempting to use cached MatchList: Succeeded. (MatchList length: 9, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:48 Connecting to startd glidein_10577@xxxxxxxxxxxxxxxxxxxx at <131.225.208.182:56701>
10/18/11 14:52:48 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:48 Matched 1412532.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.208.182:56701> glidein_10577@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Notifying the accountant
10/18/11 14:52:48 Successfully matched with glidein_10577@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Sending SEND_JOB_INFO/eom
10/18/11 14:52:48 Getting reply from schedd ...
10/18/11 14:52:48 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:48 Request 1412533.00000:
10/18/11 14:52:48 matchmakingAlgorithm: limit 575.000000 used 13.000000 pieLeft 562.000000
10/18/11 14:52:48 Concurrency Limit: total_dh_jobs is 1934.000000
10/18/11 14:52:48 Attempting to use cached MatchList: Succeeded. (MatchList length: 8, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:48 Connecting to startd glidein_718@xxxxxxxxxxxxxxxxxxxx at <131.225.209.19:32800>
10/18/11 14:52:48 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:48 Matched 1412533.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.209.19:32800> glidein_718@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Notifying the accountant
10/18/11 14:52:48 Successfully matched with glidein_718@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Sending SEND_JOB_INFO/eom
10/18/11 14:52:48 Getting reply from schedd ...
10/18/11 14:52:48 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:48 Request 1412534.00000:
10/18/11 14:52:48 matchmakingAlgorithm: limit 575.000000 used 14.000000 pieLeft 561.000000
10/18/11 14:52:48 Concurrency Limit: total_dh_jobs is 1935.000000
10/18/11 14:52:48 Attempting to use cached MatchList: Succeeded. (MatchList length: 7, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:48 Connecting to startd glidein_32315@xxxxxxxxxxxxxxxxxxxx at <131.225.208.60:43654>
10/18/11 14:52:48 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:48 Matched 1412534.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.208.60:43654> glidein_32315@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Notifying the accountant
10/18/11 14:52:48 Successfully matched with glidein_32315@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Sending SEND_JOB_INFO/eom
10/18/11 14:52:48 Getting reply from schedd ...
10/18/11 14:52:48 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:48 Request 1412535.00000:
10/18/11 14:52:48 matchmakingAlgorithm: limit 575.000000 used 15.000000 pieLeft 560.000000
10/18/11 14:52:48 Concurrency Limit: total_dh_jobs is 1936.000000
10/18/11 14:52:48 Attempting to use cached MatchList: Succeeded. (MatchList length: 6, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:48 Connecting to startd glidein_30472@xxxxxxxxxxxxxxxxxxxx at <131.225.208.61:58694>
10/18/11 14:52:48 Sending MATCH_INFO/claim id to glidein_30472@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 (Claim ID is "<131.225.208.61:58694>#1318964029#3#..." )
10/18/11 14:52:48 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:48 Matched 1412535.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.208.61:58694> glidein_30472@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Notifying the accountant
10/18/11 14:52:48 Successfully matched with glidein_30472@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Sending SEND_JOB_INFO/eom
10/18/11 14:52:48 Getting reply from schedd ...
10/18/11 14:52:48 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:48 Request 1412536.00000:
10/18/11 14:52:48 matchmakingAlgorithm: limit 575.000000 used 16.000000 pieLeft 559.000000
10/18/11 14:52:48 Concurrency Limit: total_dh_jobs is 1937.000000
10/18/11 14:52:48 Attempting to use cached MatchList: Succeeded. (MatchList length: 5, Autocluster: 3, Schedd Name: jcfree@xxxxxxxx, Schedd Address: <131.225.240.215:50394>)
10/18/11 14:52:48 Connecting to startd glidein_26072@xxxxxxxxxxxxxxxxxxxx at <131.225.238.85:37712>
10/18/11 14:52:48 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:48 Matched 1412536.0 jcfree@xxxxxxxx <131.225.240.215:50394> preempting none <131.225.238.85:37712> glidein_26072@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:48 Notifying the accountant
10/18/11 14:52:49 Successfully matched with glidein_26072@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:49 Submitter jcfree@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:49 resources used by jcfree@xxxxxxxx are 17.000000
10/18/11 14:52:49 Negotiating with jsw@xxxxxxxx at <131.225.240.215:34564>
10/18/11 14:52:49 0 seconds so far
10/18/11 14:52:49 maxAllowed = 575.000000 groupQuota = 2742.000000 groupusage = 2167.000000
10/18/11 14:52:49 Calculating submitter limit with the following parameters
10/18/11 14:52:49 SubmitterPrio = 1475.726196
10/18/11 14:52:49 SubmitterPrioFactor = 20.000000
10/18/11 14:52:49 submitterShare = 0.006726
10/18/11 14:52:49 submitterAbsShare = 0.333333
10/18/11 14:52:49 submitterLimit = 558.000000 (starved 17.000000)
10/18/11 14:52:49 submitterUsage = 143.000000
10/18/11 14:52:49 Socket to jsw@xxxxxxxx (<131.225.240.215:34564>) already in cache, reusing
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1559954.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 558.000000 used 0.000000 pieLeft 558.000000
10/18/11 14:52:49 Concurrency Limit: jsw_diskpool is 143.000000
10/18/11 14:52:49 Start of sorting MatchList (len=5)
10/18/11 14:52:49 Finished sorting MatchList
10/18/11 14:52:49 Connecting to startd glidein_4749@xxxxxxxxxxxxxxxxxxxx at <131.225.208.188:41908>
10/18/11 14:52:49 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:49 Matched 1559954.0 jsw@xxxxxxxx <131.225.240.215:34564> preempting none <131.225.208.188:41908> glidein_4749@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Notifying the accountant
10/18/11 14:52:49 Successfully matched with glidein_4749@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1559955.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 558.000000 used 1.000000 pieLeft 557.000000
10/18/11 14:52:49 Concurrency Limit: jsw_diskpool is 144.000000
10/18/11 14:52:49 Attempting to use cached MatchList: Succeeded. (MatchList length: 3, Autocluster: 63, Schedd Name: jsw@xxxxxxxx, Schedd Address: <131.225.240.215:34564>)
10/18/11 14:52:49 Connecting to startd glidein_28068@xxxxxxxxxxxxxxxxxxxx at <131.225.238.82:39314>
10/18/11 14:52:49 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:49 Matched 1559955.0 jsw@xxxxxxxx <131.225.240.215:34564> preempting none <131.225.238.82:39314> glidein_28068@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Notifying the accountant
10/18/11 14:52:49 Successfully matched with glidein_28068@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1559956.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 558.000000 used 2.000000 pieLeft 556.000000
10/18/11 14:52:49 Concurrency Limit: jsw_diskpool is 145.000000
10/18/11 14:52:49 Attempting to use cached MatchList: Succeeded. (MatchList length: 2, Autocluster: 63, Schedd Name: jsw@xxxxxxxx, Schedd Address: <131.225.240.215:34564>)
10/18/11 14:52:49 Connecting to startd glidein_11118@xxxxxxxxxxxxxxxxxxxx at <131.225.208.103:54956>
10/18/11 14:52:49 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:49 Matched 1559956.0 jsw@xxxxxxxx <131.225.240.215:34564> preempting none <131.225.208.103:54956> glidein_11118@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Notifying the accountant
10/18/11 14:52:49 Successfully matched with glidein_11118@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1559957.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 558.000000 used 3.000000 pieLeft 555.000000
10/18/11 14:52:49 Concurrency Limit: jsw_diskpool is 146.000000
10/18/11 14:52:49 Attempting to use cached MatchList: Succeeded. (MatchList length: 1, Autocluster: 63, Schedd Name: jsw@xxxxxxxx, Schedd Address: <131.225.240.215:34564>)
10/18/11 14:52:49 Connecting to startd glidein_26921@xxxxxxxxxxxxxxxxxxxx at <131.225.210.161:33540>
10/18/11 14:52:49 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:49 Matched 1559957.0 jsw@xxxxxxxx <131.225.240.215:34564> preempting none <131.225.210.161:33540> glidein_26921@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Notifying the accountant
10/18/11 14:52:49 Successfully matched with glidein_26921@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1559958.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 558.000000 used 4.000000 pieLeft 554.000000
10/18/11 14:52:49 Concurrency Limit: jsw_diskpool is 147.000000
10/18/11 14:52:49 Attempting to use cached MatchList: Succeeded. (MatchList length: 0, Autocluster: 63, Schedd Name: jsw@xxxxxxxx, Schedd Address: <131.225.240.215:34564>)
10/18/11 14:52:49 Connecting to startd glidein_15893@xxxxxxxxxxxxxxxxxxxx at <131.225.210.151:56452>
10/18/11 14:52:49 Sending PERMISSION, claim id, startdAd to schedd
10/18/11 14:52:49 Matched 1559958.0 jsw@xxxxxxxx <131.225.240.215:34564> preempting none <131.225.210.151:56452> glidein_15893@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Notifying the accountant
10/18/11 14:52:49 Successfully matched with glidein_15893@xxxxxxxxxxxxxxxxxxxx
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1559959.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 558.000000 used 5.000000 pieLeft 553.000000
10/18/11 14:52:49 Concurrency Limit: jsw_diskpool is 148.000000
10/18/11 14:52:49 Attempting to use cached MatchList: Failed (MatchList length: 0, Autocluster: 63, Schedd Name: jsw@xxxxxxxx, Schedd Address: <131.225.240.215:34564>)
10/18/11 14:52:49 Rejected 1559959.0 jsw@xxxxxxxx <131.225.240.215:34564>: no match found
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:49 Submitter jsw@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:49 resources used by jsw@xxxxxxxx are 148.000000
10/18/11 14:52:49 Negotiating with jsw@xxxxxxxx at <131.225.240.215:34172>
10/18/11 14:52:49 0 seconds so far
10/18/11 14:52:49 maxAllowed = 575.000000 groupQuota = 2742.000000 groupusage = 2167.000000
10/18/11 14:52:49 Calculating submitter limit with the following parameters
10/18/11 14:52:49 SubmitterPrio = 1475.726196
10/18/11 14:52:49 SubmitterPrioFactor = 20.000000
10/18/11 14:52:49 submitterShare = 0.006726
10/18/11 14:52:49 submitterAbsShare = 0.333333
10/18/11 14:52:49 submitterLimit = 553.000000 (starved 22.000000)
10/18/11 14:52:49 submitterUsage = 148.000000
10/18/11 14:52:49 Socket to jsw@xxxxxxxx (<131.225.240.215:34172>) already in cache, reusing
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1550116.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 553.000000 used 0.000000 pieLeft 553.000000
10/18/11 14:52:49 Concurrency Limit: jsw_diskpool is 148.000000
10/18/11 14:52:49 Rejected 1550116.0 jsw@xxxxxxxx <131.225.240.215:34172>: no match found
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:49 Submitter jsw@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:49 resources used by jsw@xxxxxxxx are 148.000000
10/18/11 14:52:49 Negotiating with kurata@xxxxxxxx at <131.225.240.215:34564>
10/18/11 14:52:49 0 seconds so far
10/18/11 14:52:49 maxAllowed = 575.000000 groupQuota = 2742.000000 groupusage = 2167.000000
10/18/11 14:52:49 Calculating submitter limit with the following parameters
10/18/11 14:52:49 SubmitterPrio = 14393.334961
10/18/11 14:52:49 SubmitterPrioFactor = 20.000000
10/18/11 14:52:49 submitterShare = 0.000690
10/18/11 14:52:49 submitterAbsShare = 0.333333
10/18/11 14:52:49 submitterLimit = 553.000000 (starved 22.000000)
10/18/11 14:52:49 submitterUsage = 1420.000000
10/18/11 14:52:49 Socket to kurata@xxxxxxxx (<131.225.240.215:34564>) already in cache, reusing
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1545639.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 553.000000 used 0.000000 pieLeft 553.000000
10/18/11 14:52:49 Rejected 1545639.0 kurata@xxxxxxxx <131.225.240.215:34564>: no match found
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:49 Submitter kurata@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:49 resources used by kurata@xxxxxxxx are 1420.000000
10/18/11 14:52:49 Negotiating with kurata@xxxxxxxx at <131.225.240.215:34172>
10/18/11 14:52:49 0 seconds so far
10/18/11 14:52:49 maxAllowed = 575.000000 groupQuota = 2742.000000 groupusage = 2167.000000
10/18/11 14:52:49 Calculating submitter limit with the following parameters
10/18/11 14:52:49 SubmitterPrio = 14393.334961
10/18/11 14:52:49 SubmitterPrioFactor = 20.000000
10/18/11 14:52:49 submitterShare = 0.000690
10/18/11 14:52:49 submitterAbsShare = 0.333333
10/18/11 14:52:49 submitterLimit = 553.000000 (starved 22.000000)
10/18/11 14:52:49 submitterUsage = 1420.000000
10/18/11 14:52:49 Socket to kurata@xxxxxxxx (<131.225.240.215:34172>) already in cache, reusing
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1520541.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 553.000000 used 0.000000 pieLeft 553.000000
10/18/11 14:52:49 Rejected 1520541.0 kurata@xxxxxxxx <131.225.240.215:34172>: no match found
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:49 Submitter kurata@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:49 resources used by kurata@xxxxxxxx are 1420.000000
10/18/11 14:52:49 Negotiating with kurata@xxxxxxxx at <131.225.240.215:50394>
10/18/11 14:52:49 0 seconds so far
10/18/11 14:52:49 maxAllowed = 575.000000 groupQuota = 2742.000000 groupusage = 2167.000000
10/18/11 14:52:49 Calculating submitter limit with the following parameters
10/18/11 14:52:49 SubmitterPrio = 14393.334961
10/18/11 14:52:49 SubmitterPrioFactor = 20.000000
10/18/11 14:52:49 submitterShare = 0.000690
10/18/11 14:52:49 submitterAbsShare = 0.333333
10/18/11 14:52:49 submitterLimit = 553.000000 (starved 22.000000)
10/18/11 14:52:49 submitterUsage = 1420.000000
10/18/11 14:52:49 Socket to kurata@xxxxxxxx (<131.225.240.215:50394>) already in cache, reusing
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1379138.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 553.000000 used 0.000000 pieLeft 553.000000
10/18/11 14:52:49 Rejected 1379138.0 kurata@xxxxxxxx <131.225.240.215:50394>: no match found
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:49 Submitter kurata@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:49 resources used by kurata@xxxxxxxx are 1420.000000
10/18/11 14:52:49 resources used scheddUsed= 4573.000000
10/18/11 14:52:49 negotiateWithGroup resources used scheddAds length 0
10/18/11 14:52:49 Group group_ntp - starvation= 0.805043 (679/843.433) prio= 8872.17
10/18/11 14:52:49 Group group_ntp - BEGIN NEGOTIATION
10/18/11 14:52:49 Phase 3: Sorting submitter ads by priority ...
10/18/11 14:52:49 Ignoring submitter group_ntp.cdfprd_ntp@xxxxxxxx with no idle jobs
10/18/11 14:52:49 maxAllowed = 164.432983 groupQuota = 843.432983 groupusage = 679.000000
10/18/11 14:52:49 Phase 4.1: Negotiating with schedds ...
10/18/11 14:52:49 numSlots = 843
10/18/11 14:52:49 slotWeightTotal = 843.432983
10/18/11 14:52:49 pieLeft = 164.433
10/18/11 14:52:49 NormalFactor = 1.000000
10/18/11 14:52:49 MaxPrioValue = 8872.168945
10/18/11 14:52:49 NumSubmitterAds = 3
10/18/11 14:52:49 Negotiating with group_ntp.cdfprd_ntp@xxxxxxxx at <131.225.240.215:34564>
10/18/11 14:52:49 0 seconds so far
10/18/11 14:52:49 maxAllowed = 164.432983 groupQuota = 843.432983 groupusage = 679.000000
10/18/11 14:52:49 Calculating submitter limit with the following parameters
10/18/11 14:52:49 SubmitterPrio = 8872.168945
10/18/11 14:52:49 SubmitterPrioFactor = 20.000000
10/18/11 14:52:49 submitterShare = 1.000000
10/18/11 14:52:49 submitterAbsShare = 1.000000
10/18/11 14:52:49 submitterLimit = 164.432983
10/18/11 14:52:49 submitterUsage = 679.000000
10/18/11 14:52:49 Socket to group_ntp.cdfprd_ntp@xxxxxxxx (<131.225.240.215:34564>) already in cache, reusing
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1541891.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 164.432983 used 0.000000 pieLeft 164.432983
10/18/11 14:52:49 Concurrency Limit: total_dh_jobs is 1938.000000
10/18/11 14:52:49 Rejected 1541891.0 group_ntp.cdfprd_ntp@xxxxxxxx <131.225.240.215:34564>: no match found
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:49 Submitter group_ntp.cdfprd_ntp@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:49 resources used by group_ntp.cdfprd_ntp@xxxxxxxx are 679.000000
10/18/11 14:52:49 Negotiating with group_ntp.cdfprd_ntp@xxxxxxxx at <131.225.240.215:34172>
10/18/11 14:52:49 0 seconds so far
10/18/11 14:52:49 maxAllowed = 164.432983 groupQuota = 843.432983 groupusage = 679.000000
10/18/11 14:52:49 Calculating submitter limit with the following parameters
10/18/11 14:52:49 SubmitterPrio = 8872.168945
10/18/11 14:52:49 SubmitterPrioFactor = 20.000000
10/18/11 14:52:49 submitterShare = 1.000000
10/18/11 14:52:49 submitterAbsShare = 1.000000
10/18/11 14:52:49 submitterLimit = 164.432983
10/18/11 14:52:49 submitterUsage = 679.000000
10/18/11 14:52:49 Socket to group_ntp.cdfprd_ntp@xxxxxxxx (<131.225.240.215:34172>) already in cache, reusing
10/18/11 14:52:49 Sending SEND_JOB_INFO/eom
10/18/11 14:52:49 Getting reply from schedd ...
10/18/11 14:52:49 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:49 Request 1548235.00000:
10/18/11 14:52:49 matchmakingAlgorithm: limit 164.432983 used 0.000000 pieLeft 164.432983
10/18/11 14:52:49 Concurrency Limit: total_dh_jobs is 1938.000000
10/18/11 14:52:50 Rejected 1548235.0 group_ntp.cdfprd_ntp@xxxxxxxx <131.225.240.215:34172>: no match found
10/18/11 14:52:50 Sending SEND_JOB_INFO/eom
10/18/11 14:52:50 Getting reply from schedd ...
10/18/11 14:52:50 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:50 Submitter group_ntp.cdfprd_ntp@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:50 resources used by group_ntp.cdfprd_ntp@xxxxxxxx are 679.000000
10/18/11 14:52:50 Negotiating with group_ntp.cdfprd_ntp@xxxxxxxx at <131.225.240.215:52592>
10/18/11 14:52:50 0 seconds so far
10/18/11 14:52:50 maxAllowed = 164.432983 groupQuota = 843.432983 groupusage = 679.000000
10/18/11 14:52:50 Calculating submitter limit with the following parameters
10/18/11 14:52:50 SubmitterPrio = 8872.168945
10/18/11 14:52:50 SubmitterPrioFactor = 20.000000
10/18/11 14:52:50 submitterShare = 1.000000
10/18/11 14:52:50 submitterAbsShare = 1.000000
10/18/11 14:52:50 submitterLimit = 164.432983
10/18/11 14:52:50 submitterUsage = 679.000000
10/18/11 14:52:50 Socket to group_ntp.cdfprd_ntp@xxxxxxxx (<131.225.240.215:52592>) already in cache, reusing
10/18/11 14:52:50 Sending SEND_JOB_INFO/eom
10/18/11 14:52:50 Getting reply from schedd ...
10/18/11 14:52:50 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:50 Request 20157325.00000:
10/18/11 14:52:50 matchmakingAlgorithm: limit 164.432983 used 0.000000 pieLeft 164.432983
10/18/11 14:52:50 Concurrency Limit: total_dh_jobs is 1938.000000
10/18/11 14:52:50 Rejected 20157325.0 group_ntp.cdfprd_ntp@xxxxxxxx <131.225.240.215:52592>: no match found
10/18/11 14:52:50 Sending SEND_JOB_INFO/eom
10/18/11 14:52:50 Getting reply from schedd ...
10/18/11 14:52:50 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:50 Submitter group_ntp.cdfprd_ntp@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:50 resources used by group_ntp.cdfprd_ntp@xxxxxxxx are 679.000000
10/18/11 14:52:50 resources used scheddUsed= 2037.000000
10/18/11 14:52:50 negotiateWithGroup resources used scheddAds length 0
10/18/11 14:52:50 Group group_highprio - starvation= 0.823627 (495/601) prio= 3248.76
10/18/11 14:52:50 Group group_highprio - BEGIN NEGOTIATION
10/18/11 14:52:50 Phase 3: Sorting submitter ads by priority ...
10/18/11 14:52:50 Ignoring submitter group_highprio.viviana@xxxxxxxx with no idle jobs
10/18/11 14:52:50 Ignoring submitter group_highprio.cdfprd_ntp@xxxxxxxx with no idle jobs
10/18/11 14:52:50 Ignoring submitter group_highprio.whh0407@xxxxxxxx with no idle jobs
10/18/11 14:52:50 Ignoring submitter group_highprio.whh0407@xxxxxxxx with no idle jobs
10/18/11 14:52:50 maxAllowed = 106.000000 groupQuota = 601.000000 groupusage = 495.000000
10/18/11 14:52:50 Phase 4.1: Negotiating with schedds ...
10/18/11 14:52:50 numSlots = 601
10/18/11 14:52:50 slotWeightTotal = 601.000000
10/18/11 14:52:50 pieLeft = 106.000
10/18/11 14:52:50 NormalFactor = 1.000000
10/18/11 14:52:50 MaxPrioValue = 3169.230957
10/18/11 14:52:50 NumSubmitterAds = 1
10/18/11 14:52:50 Negotiating with group_highprio.whh0407@xxxxxxxx at <131.225.240.215:34564>
10/18/11 14:52:50 0 seconds so far
10/18/11 14:52:50 maxAllowed = 106.000000 groupQuota = 601.000000 groupusage = 495.000000
10/18/11 14:52:50 Calculating submitter limit with the following parameters
10/18/11 14:52:50 SubmitterPrio = 3169.230957
10/18/11 14:52:50 SubmitterPrioFactor = 20.000000
10/18/11 14:52:50 submitterShare = 1.000000
10/18/11 14:52:50 submitterAbsShare = 1.000000
10/18/11 14:52:50 submitterLimit = 106.000000
10/18/11 14:52:50 submitterUsage = 486.000000
10/18/11 14:52:50 Socket to group_highprio.whh0407@xxxxxxxx (<131.225.240.215:34564>) already in cache, reusing
10/18/11 14:52:50 Sending SEND_JOB_INFO/eom
10/18/11 14:52:50 Getting reply from schedd ...
10/18/11 14:52:50 Got JOB_INFO command; getting classad/eom
10/18/11 14:52:50 Request 1577571.00000:
10/18/11 14:52:50 matchmakingAlgorithm: limit 106.000000 used 0.000000 pieLeft 106.000000
10/18/11 14:52:50 Rejected 1577571.0 group_highprio.whh0407@xxxxxxxx <131.225.240.215:34564>: no match found
10/18/11 14:52:50 Sending SEND_JOB_INFO/eom
10/18/11 14:52:50 Getting reply from schedd ...
10/18/11 14:52:50 Got NO_MORE_JOBS; done negotiating
10/18/11 14:52:50 Submitter group_highprio.whh0407@xxxxxxxx got all it wants; removing it.
10/18/11 14:52:50 resources used by group_highprio.whh0407@xxxxxxxx are 486.000000
10/18/11 14:52:50 resources used scheddUsed= 486.000000
10/18/11 14:52:50 negotiateWithGroup resources used scheddAds length 0
10/18/11 14:52:50 Group group_prd - starvation= 1.26975 (952/749.752) prio= 18276.8
10/18/11 14:52:50 Group group_prd - skipping, at or over quota (usage=952)
10/18/11 14:52:50 Group group_italy - starvation= 4.5488 (790/173.672) prio= 11371.3
10/18/11 14:52:50 Group group_italy - skipping, at or over quota (usage=790)
10/18/11 14:52:50 Group group_fixedwntest - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_fixedwntest - skipping, zero slots allocated
10/18/11 14:52:50 Group group_florida - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_florida - skipping, zero slots allocated
10/18/11 14:52:50 Group group_karlsruhe - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_karlsruhe - skipping, zero slots allocated
10/18/11 14:52:50 Group group_mit - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_mit - skipping, zero slots allocated
10/18/11 14:52:50 Group group_alignment - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_alignment - skipping, zero slots allocated
10/18/11 14:52:50 Group group_physmon - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_physmon - skipping, zero slots allocated
10/18/11 14:52:50 Group group_sam - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_sam - skipping, zero slots allocated
10/18/11 14:52:50 Group group_dqm - starvation= 1.79769e+308 (0/0) prio= 10.3991
10/18/11 14:52:50 Group group_dqm - skipping, zero slots allocated
10/18/11 14:52:50 Group group_japan - starvation= 1.79769e+308 (0/0) prio= 751.406
10/18/11 14:52:50 Group group_japan - skipping, zero slots allocated
10/18/11 14:52:50 Group group_calib - starvation= 1.79769e+308 (0/0) prio= 775.417
10/18/11 14:52:50 Group group_calib - skipping, zero slots allocated
10/18/11 14:52:50 Group group_dbg - starvation= 1.79769e+308 (0/0) prio= 5000
10/18/11 14:52:50 Group group_dbg - skipping, zero slots allocated
10/18/11 14:52:50 Group group_btagging - starvation= 1.79769e+308 (0/0) prio= 5000
10/18/11 14:52:50 Group group_btagging - skipping, zero slots allocated
10/18/11 14:52:50 group quotas: Group <none> allocated= 2742 usage= 2189
10/18/11 14:52:50 group quotas: Group <none> - resetting requested to 2189
10/18/11 14:52:50 group quotas: Group group_alignment allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_btagging allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_calib allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_dbg allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_dqm allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_fixedwntest allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_florida allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_fnal allocated= 4 usage= 1
10/18/11 14:52:50 group quotas: Group group_fnal - resetting requested to 1
10/18/11 14:52:50 group quotas: Group group_highprio allocated= 601 usage= 495
10/18/11 14:52:50 group quotas: Group group_highprio - resetting requested to 495
10/18/11 14:52:50 group quotas: Group group_italy allocated= 173.672 usage= 790
10/18/11 14:52:50 group quotas: Group group_japan allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_karlsruhe allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_mcprod allocated= 3 usage= 2
10/18/11 14:52:50 group quotas: Group group_mcprod - resetting requested to 2
10/18/11 14:52:50 group quotas: Group group_mit allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_ntp allocated= 843.433 usage= 679
10/18/11 14:52:50 group quotas: Group group_ntp - resetting requested to 679
10/18/11 14:52:50 group quotas: Group group_physmon allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_prd allocated= 749.752 usage= 952
10/18/11 14:52:50 group quotas: Group group_sam allocated= 0 usage= 0
10/18/11 14:52:50 Round 1 totals: allocated= 5116.86 usage= 4289.42
10/18/11 14:52:50 group quotas: allocation round 2
10/18/11 14:52:50 group quotas: fairshare (1): group= <none> quota= 5682.04 requested= 2189
10/18/11 14:52:50 group quotas: fairshare (2): group= <none> quota= 5682.04 allocated= 2189 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_alignment quota= 102.16 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_alignment quota= 102.16 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_btagging quota= 204.32 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_btagging quota= 204.32 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_calib quota= 214.536 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_calib quota= 214.536 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_dbg quota= 51.08 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_dbg quota= 51.08 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_dqm quota= 51.08 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_dqm quota= 51.08 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_fixedwntest quota= 51.08 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_fixedwntest quota= 51.08 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_florida quota= 20.432 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_florida quota= 20.432 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_fnal quota= 214.536 requested= 1
10/18/11 14:52:50 group quotas: fairshare (2): group= group_fnal quota= 214.536 allocated= 1 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_highprio quota= 817.28 requested= 495
10/18/11 14:52:50 group quotas: fairshare (2): group= group_highprio quota= 817.28 allocated= 495 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_italy quota= 173.672 requested= 13102
10/18/11 14:52:50 group quotas: fairshare (2): group= group_italy quota= 173.672 allocated= 173.672 requested= 12928.3
10/18/11 14:52:50 group quotas: fairshare (1): group= group_japan quota= 214.536 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_japan quota= 214.536 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_karlsruhe quota= 51.08 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_karlsruhe quota= 51.08 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_mcprod quota= 478.722 requested= 2
10/18/11 14:52:50 group quotas: fairshare (2): group= group_mcprod quota= 478.722 allocated= 2 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_mit quota= 30.648 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_mit quota= 30.648 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_ntp quota= 843.433 requested= 679
10/18/11 14:52:50 group quotas: fairshare (2): group= group_ntp quota= 843.433 allocated= 679 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_physmon quota= 10.216 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_physmon quota= 10.216 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: fairshare (1): group= group_prd quota= 749.752 requested= 2902
10/18/11 14:52:50 group quotas: fairshare (2): group= group_prd quota= 749.752 allocated= 749.752 requested= 2152.25
10/18/11 14:52:50 group quotas: fairshare (1): group= group_sam quota= 255.4 requested= 0
10/18/11 14:52:50 group quotas: fairshare (2): group= group_sam quota= 255.4 allocated= 0 requested= 0
10/18/11 14:52:50 group quotas: allocate-surplus (1): group= <none> surplus= 5926.58 subtree-requested= 0
10/18/11 14:52:50 group quotas: fairshare (3): group= <none> surplus= 5926.58 subtree_requested= 0
10/18/11 14:52:50 group quotas: group= <none> quota= 5682.04 requested= 2189 allocated= 2189 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_alignment quota= 102.16 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_btagging quota= 204.32 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_calib quota= 214.536 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_dbg quota= 51.08 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_dqm quota= 51.08 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_fixedwntest quota= 51.08 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_florida quota= 20.432 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_fnal quota= 214.536 requested= 1 allocated= 1 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_highprio quota= 817.28 requested= 495 allocated= 495 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_italy quota= 173.672 requested= 13102 allocated= 173.672 unallocated= 12928.3
10/18/11 14:52:50 group quotas: group= group_japan quota= 214.536 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_karlsruhe quota= 51.08 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_mcprod quota= 478.722 requested= 2 allocated= 2 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_mit quota= 30.648 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_ntp quota= 843.433 requested= 679 allocated= 679 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_physmon quota= 10.216 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: group= group_prd quota= 749.752 requested= 2902 allocated= 749.752 unallocated= 2152.25
10/18/11 14:52:50 group quotas: group= group_sam quota= 255.4 requested= 0 allocated= 0 unallocated= 0
10/18/11 14:52:50 group quotas: groups= 19 requesting= 7 served= 7 unserved= 0 slots= 10216 requested= 19370 allocated= 4289.42 surplus= 5926.58
10/18/11 14:52:50 group quotas: entering RR iteration n= 0
10/18/11 14:52:50 Group group_fnal - starvation= 1 (1/1) prio= 553.439
10/18/11 14:52:50 Group group_fnal - skipping, at or over quota (usage=1)
10/18/11 14:52:50 Group group_highprio - starvation= 1 (495/495) prio= 3248.76
10/18/11 14:52:50 Group group_highprio - skipping, at or over quota (usage=495)
10/18/11 14:52:50 Group group_ntp - starvation= 1 (679/679) prio= 8872.17
10/18/11 14:52:50 Group group_ntp - skipping, at or over quota (usage=679)
10/18/11 14:52:50 Group group_mcprod - starvation= 1 (2/2) prio= 183878
10/18/11 14:52:50 Group group_mcprod - skipping, at or over quota (usage=2)
10/18/11 14:52:50 Group <none> - starvation= 1 (2189/2189) prio= 2.01015e+07
10/18/11 14:52:50 Group <none> - skipping, at or over quota (usage=2189)
10/18/11 14:52:50 Group group_prd - starvation= 1.26975 (952/749.752) prio= 18276.8
10/18/11 14:52:50 Group group_prd - skipping, at or over quota (usage=952)
10/18/11 14:52:50 Group group_italy - starvation= 4.5488 (790/173.672) prio= 11371.3
10/18/11 14:52:50 Group group_italy - skipping, at or over quota (usage=790)
10/18/11 14:52:50 Group group_fixedwntest - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_fixedwntest - skipping, zero slots allocated
10/18/11 14:52:50 Group group_florida - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_florida - skipping, zero slots allocated
10/18/11 14:52:50 Group group_karlsruhe - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_karlsruhe - skipping, zero slots allocated
10/18/11 14:52:50 Group group_alignment - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_alignment - skipping, zero slots allocated
10/18/11 14:52:50 Group group_mit - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_mit - skipping, zero slots allocated
10/18/11 14:52:50 Group group_physmon - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_physmon - skipping, zero slots allocated
10/18/11 14:52:50 Group group_sam - starvation= 1.79769e+308 (0/0) prio= 10
10/18/11 14:52:50 Group group_sam - skipping, zero slots allocated
10/18/11 14:52:50 Group group_dqm - starvation= 1.79769e+308 (0/0) prio= 10.3991
10/18/11 14:52:50 Group group_dqm - skipping, zero slots allocated
10/18/11 14:52:50 Group group_japan - starvation= 1.79769e+308 (0/0) prio= 751.406
10/18/11 14:52:50 Group group_japan - skipping, zero slots allocated
10/18/11 14:52:50 Group group_calib - starvation= 1.79769e+308 (0/0) prio= 775.417
10/18/11 14:52:50 Group group_calib - skipping, zero slots allocated
10/18/11 14:52:50 Group group_dbg - starvation= 1.79769e+308 (0/0) prio= 5000
10/18/11 14:52:50 Group group_dbg - skipping, zero slots allocated
10/18/11 14:52:50 Group group_btagging - starvation= 1.79769e+308 (0/0) prio= 5000
10/18/11 14:52:50 Group group_btagging - skipping, zero slots allocated
10/18/11 14:52:50 group quotas: Group <none> allocated= 2189 usage= 2189
10/18/11 14:52:50 group quotas: Group group_alignment allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_btagging allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_calib allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_dbg allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_dqm allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_fixedwntest allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_florida allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_fnal allocated= 1 usage= 1
10/18/11 14:52:50 group quotas: Group group_highprio allocated= 495 usage= 495
10/18/11 14:52:50 group quotas: Group group_italy allocated= 173.672 usage= 790
10/18/11 14:52:50 group quotas: Group group_japan allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_karlsruhe allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_mcprod allocated= 2 usage= 2
10/18/11 14:52:50 group quotas: Group group_mit allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_ntp allocated= 679 usage= 679
10/18/11 14:52:50 group quotas: Group group_physmon allocated= 0 usage= 0
10/18/11 14:52:50 group quotas: Group group_prd allocated= 749.752 usage= 952
10/18/11 14:52:50 group quotas: Group group_sam allocated= 0 usage= 0
10/18/11 14:52:50 Round 2 totals: allocated= 4289.42 usage= 4289.42
10/18/11 14:52:50 ---------- Finished Negotiation Cycle ----------