<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 3.2//EN">
<HTML>
<HEAD>
<META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=iso-8859-1">
<META NAME="Generator" CONTENT="MS Exchange Server version 6.5.7650.28">
<TITLE>FW: maui pausing on Torque multiple qsubs</TITLE>
</HEAD>
<BODY>
<!-- Converted from text/plain format -->

<P><FONT SIZE=2>Hi all,<BR>
<BR>
Didnt get any replies last time - does anyone know why Maui pauses for 15 mins after:<BR>
ERROR:&nbsp;&nbsp;&nbsp; cannot get node info: Premature end of message<BR>
or just as good, does anyone know where this timeout can be configured?<BR>
<BR>
Craig<BR>
<BR>
-----Original Message-----<BR>
From: Craig Macdonald<BR>
Sent: Fri 1/26/2007 6:36 PM<BR>
To: mauiusers@supercluster.org; torqueusers@supercluster.org<BR>
Subject: maui pausing on Torque multiple qsubs<BR>
<BR>
Hi there,<BR>
<BR>
I have a problem extremely similar to<BR>
<A HREF="http://www.clusterresources.com/pipermail/torqueusers/2006-April/003576.html">http://www.clusterresources.com/pipermail/torqueusers/2006-April/003576.html</A><BR>
<BR>
When doing multiple qsubs, Maui starts scheduling, then times out<BR>
getting node info.<BR>
However, it doesn't start scheduling again for a significant amount of<BR>
time. (15+mins)<BR>
The most recent time, this happened to me while qdel-ing 3 jobs:<BR>
<BR>
[craigm@bohol terrier]$qdel 545 546 547<BR>
No Permission.<BR>
qdel: cannot connect to server trmaster (errno=15007)<BR>
[craigm@bohol terrier]$qstat<BR>
Job id&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Name&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; User&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Time Use S Queue<BR>
------------------- ---------------- --------------- -------- - -----<BR>
547.trmaster&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; index_wt2g_2&nbsp;&nbsp;&nbsp;&nbsp; craigm&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; 0 H verylong<BR>
[craigm@bohol terrier]$qdel 547<BR>
<BR>
<BR>
At this point, maui will do it's pause.<BR>
<BR>
This happens with torque-2.1.6 and maui 3.2.6p17<BR>
<BR>
My issue is that Maui seems to recieve a timeout from the libpbs, but<BR>
doesnt seem to know what to do with it<BR>
for a significant amount of time (till something else times out?). Is<BR>
there any timeouts we can configure in Maui to reduce this.<BR>
<BR>
The alternative route is to trace why the timeout occur in pbs_server.<BR>
<BR>
Configurations and logs below. Logs are from a previous occurrence of<BR>
this event.<BR>
<BR>
Many thanks<BR>
<BR>
Craig<BR>
<BR>
I have Torque config<BR>
set server node_check_rate = 150<BR>
set server tcp_timeout = 6<BR>
set server poll_jobs = True<BR>
set server scheduler_iteration = 600<BR>
<BR>
and relevant bit for Maui:<BR>
RMPOLLINTERVAL&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; 00:00:30<BR>
<BR>
Maui Log<BR>
=======<BR>
01/23 22:58:05 MResUpdateStats()<BR>
01/23 22:58:05 INFO:&nbsp;&nbsp;&nbsp;&nbsp; current util[2097]:&nbsp; 7/8 (87.50%)&nbsp; PH: 28.43%&nbsp;<BR>
active jobs: 2 of 2 (completed: 413)<BR>
01/23 22:58:05 MQueueCheckStatus()<BR>
01/23 22:58:05 MNodeCheckStatus()<BR>
01/23 22:58:05 ALERT:&nbsp;&nbsp;&nbsp; node 'trnode03' sync from expected state 'Idle'<BR>
to state 'Running' at Tue Jan 23 22:58:05<BR>
01/23 22:58:05 ALERT:&nbsp;&nbsp;&nbsp; node 'trnode04' sync from expected state 'Idle'<BR>
to state 'Running' at Tue Jan 23 22:58:05<BR>
01/23 22:58:05 ALERT:&nbsp;&nbsp;&nbsp; node 'trnode05' sync from expected state 'Idle'<BR>
to state 'Running' at Tue Jan 23 22:58:05<BR>
01/23 22:58:05 ALERT:&nbsp;&nbsp;&nbsp; node 'trnode06' sync from expected state 'Idle'<BR>
to state 'Running' at Tue Jan 23 22:58:05<BR>
01/23 22:58:05 ALERT:&nbsp;&nbsp;&nbsp; node 'trnode08' sync from expected state 'Idle'<BR>
to state 'Running' at Tue Jan 23 22:58:05<BR>
01/23 22:58:05 MUClearChild(PID)<BR>
01/23 22:58:05 INFO:&nbsp;&nbsp;&nbsp;&nbsp; scheduling complete.&nbsp; sleeping 30 seconds<BR>
01/23 22:58:14 INFO:&nbsp;&nbsp;&nbsp;&nbsp; connect request from 130.209.249.20<BR>
01/23 22:58:14 INFO:&nbsp;&nbsp;&nbsp;&nbsp; received service request from host 'trmaster'<BR>
01/23 22:58:14 MSURecvPacket(9,BufP,4,NULL,100000,SC)<BR>
01/23 22:58:14 INFO:&nbsp;&nbsp;&nbsp;&nbsp; connect request from 130.209.249.20<BR>
01/23 22:58:14 INFO:&nbsp;&nbsp;&nbsp;&nbsp; received service request from host 'trmaster'<BR>
01/23 22:58:14 MSURecvPacket(9,BufP,4,NULL,100000,SC)<BR>
01/23 22:58:14 ServerProcessRequests()<BR>
01/23 22:58:14 INFO:&nbsp;&nbsp;&nbsp;&nbsp; not rolling logs (8941183 &lt; 10000000)<BR>
01/23 22:58:14 MResAdjust(NULL,0,0)<BR>
01/23 22:58:14 MStatInitializeActiveSysUsage()<BR>
01/23 22:58:14 MStatClearUsage([NONE],Active)<BR>
01/23 22:58:14 ServerUpdate()<BR>
01/23 22:58:14 MSysUpdateTime()<BR>
01/23 22:58:14 INFO:&nbsp;&nbsp;&nbsp;&nbsp; starting iteration 2098<BR>
01/23 22:58:14 MRMGetInfo()<BR>
01/23 22:58:14 MClusterClearUsage()<BR>
01/23 22:58:14 MRMClusterQuery()<BR>
01/23 22:58:14 MPBSClusterQuery(base,RCount,SC)<BR>
01/23 22:58:23 ERROR:&nbsp;&nbsp;&nbsp; cannot get node info: Premature end of message<BR>
&lt;PAUSE HERE&gt;<BR>
01/23 23:13:44 ALERT:&nbsp;&nbsp;&nbsp; cannot load cluster resources on RM (RM 'base'<BR>
failed in function 'clusterquery')<BR>
01/23 23:13:44 WARNING:&nbsp; no resources detected<BR>
01/23 23:13:44 MRMWorkloadQuery()<BR>
01/23 23:13:44 MPBSWorkloadQuery(base,JCount,SC)<BR>
01/23 23:13:44 MPBSInitialize(base,SC)<BR>
01/23 23:13:45 MSUListen(S)<BR>
01/23 23:13:45 INFO:&nbsp;&nbsp;&nbsp;&nbsp; opened service socket on port 15004<BR>
01/23 23:13:45 __MPBSSystemQuery(base,RCount,SC)<BR>
01/23 23:13:45 INFO:&nbsp;&nbsp;&nbsp;&nbsp; connected to PBS server :0 on sd 1<BR>
01/23 23:13:45 MPBSJobUpdate(422,422.trmaster,TaskList,0)<BR>
01/23 23:13:45 MStatUpdateActiveJobUsage(422)<BR>
<BR>
Torque pbs_server log<BR>
================<BR>
01/23/2007 22:58:14;0040;PBS_Server;Svr;trmaster;Scheduler sent command new<BR>
01/23/2007 22:58:14;0100;PBS_Server;Req;;Type AuthenticateUser request<BR>
received from craigm@trangan, sock=13<BR>
01/23/2007 22:58:14;0100;PBS_Server;Req;;Type QueueJob request received<BR>
from craigm@trangan, sock=11<BR>
01/23/2007 22:58:14;0100;PBS_Server;Req;;Type JobScript request received<BR>
from craigm@trangan, sock=11<BR>
01/23/2007 22:58:14;0100;PBS_Server;Req;;Type ReadyToCommit request<BR>
received from craigm@trangan, sock=11<BR>
01/23/2007 22:58:14;0100;PBS_Server;Req;;Type Commit request received<BR>
from craigm@trangan, sock=11<BR>
01/23/2007 22:58:14;0100;PBS_Server;Job;490.trmaster;enqueuing into<BR>
feed, state 1 hop 1<BR>
01/23/2007 22:58:14;0100;PBS_Server;Job;490.trmaster;dequeuing from<BR>
feed, state QUEUED<BR>
01/23/2007 22:58:14;0100;PBS_Server;Job;490.trmaster;enqueuing into<BR>
verylong, state 1 hop 1<BR>
01/23/2007 22:58:14;0008;PBS_Server;Job;490.trmaster;Job Queued at<BR>
request of craigm@trangan, owner = craigm@trangan, job name =<BR>
tagDisk454, queue = verylong<BR>
01/23/2007 22:58:14;0100;PBS_Server;Req;;Type AuthenticateUser request<BR>
received from craigm@trangan, sock=12<BR>
01/23/2007 22:58:39;0100;PBS_Server;Req;;Type QueueJob request received<BR>
from craigm@trangan, sock=11<BR>
01/23/2007 22:58:39;0040;PBS_Server;Svr;trmaster;Scheduler sent command time<BR>
01/23/2007 22:58:39;0100;PBS_Server;Req;;Type StatusNode request<BR>
received from craigm@trmaster, sock=9<BR>
<BR>
<BR>
<BR>
</FONT>
</P>

</BODY>
</HTML>