Measure thread execution (in C, unix)

Hi,

I have a simulation program which creates two threads and I would like to know if I can measure the time of each individual thread. Threads communicate (I use pthread to manage them) and I want to measure communication time. I found a solution with clock_gettime and CLOCK_THREAD_CPUTIME_ID but nothing for Solaris OS.
French forums are insufficient, so I hope to find help here :slight_smile:

Note: two threads on identical topic merged. Please do not post twice on the same topic - this kind of hodge-podge results from doing that.

I'm not quite sure I understand the question. Sorry. :confused: What's the difference between thread time and system time?

I have two threads with WRITE/READ between them. The synchronisation works (I use pthread library) but I must calculate the execution of the READ function.
A part of my program :

void ReadWithWait_##Type (_C_ReadWithWait_##Type *C){ \
    _int Length_ = 0; \
    SYSTEM_TIME_TYPE entry; \
    SYSTEM_TIME_TYPE curr; \
    RETURN_CODE_TYPE retCode; \
    Dur waitDur = 0; \
 \
    GET_TIME(&entry, &retCode); \
    C->_O0_Validity_ = INVALID; \
\
    if (C->_M_init == true) \
    { \
        CREATE_SAMPLING_PORT(...)\
        (C->_O1_Message_) = *(C->_I3_InitMessage_); \
        C->_PrevMsg = *(C->_I3_InitMessage_); \
        C->_M_init = false; \
    } \
    while((waitDur <= (C->_I2_TimeOut_)) && ((C->_O0_Validity_) == INVALID)) \
    { \
        READ_SAMPLING_MESSAGE( ... ); \
        GET_TIME(&curr, &retCode); \
        waitDur = (Dur)(curr - entry); \
    } \
    if (waitDur > (C->_I2_TimeOut_)) \
    { \
        (C->_O0_Validity_) = INVALID; \
        (C->_O2_ReturnCode_)= (ReturnCode)TIMED_OUT; \
 printf("TIME OUT 2 : %d > %d\n",waitDur,(C->_I2_TimeOut_));\
    } \
    (...)
    C->_PrevMsg = (C->_O1_Message_); \
}

Actually, GET_TIME uses gethrtime() => it's system time. But between my two GET_TIME, I'm not sure that only this function is executed. Processor switchs between thread 1 and 2 so waitdur is variable, that's why I want to know a solution to calculate only thread time.

So, something to count CPU time the thread has spent running since last, but not count time the thread has spent suspended?

Exactly.
another topic explains this problem better than me but doesn't give a solution : http://www.linuxforums.org/forum/programming-scripting/101371-pthreads-thread-time-vs-process-time.html

Which version of Solaris are you using? I believe that CLOCK_THREAD_CPUTIME_ID was added in one of the later Solaris 10 updates. However, it might have only been added to the header to pass the UNIX03 VSTH test suite and not actually implemented.

Another possible way is to use getrusage(RUSAGE_LWP, ....) In Solaris 9 and above the default correspondence between threads and LWPs is 1x1, not MxN.

1 Like

Thank you for reply :b:

I already try to use CLOCK_THREAD_CPUTIME_ID but it does'nt work with Solaris 8.
I'm trying to use getrusage with RUSAGE_SELF (RUSAGE_LWP is not available in sys/resource.h, there's just RUSEGE_SELF and RUSAGE_CHILDREN). I hope it's a way to find solution ...

---------- Post updated at 11:37 AM ---------- Previous update was at 11:36 AM ----------

Bad news, I have a strange behaviour with getrusage.
My old function GET_TIME :

void GET_TIME(SYSTEM_TIME_TYPE * SystemTime, RETURN_CODE_TYPE * ReturnCode)
{ 
* SystemTime = gethrtime(); *ReturnCode=NO_ERROR;
}

The new one :

void GET_TIME2(SYSTEM_TIME_TYPE * SystemTime, RETURN_CODE_TYPE * ReturnCode)
{
    ret = getrusage(RUSAGE_SELF, &usage);
    * SystemTime = (usage.ru_utime.tv_sec*1000000 + usage.ru_utime.tv_usec)*1000;
    *ReturnCode=NO_ERROR;
}

Between two GET_TIME, time is 200 000 ns approximately.
With GET_TIME2, this value can reach 10 000 000 or -7000 and it's equal to 0 majority... :wall:

Hi
I have this posted in the Solaris section also so apologies if not permitted to post here also.

problem is that my cron will not run a script that runs perfectly fine from command line. The script is written in sh but contains reference to a .pl.

Initial script only had path #!/usr/bin/sh and does refer to a .pl script.
I have amedned now to have two paths with

#!/usr/bin/sh [At the start as normal]

&

#!/usr/bin/perl -w [before perl script is run]

This had no affect and the cron still does not run the script....

ANy help greatly appreciated

Well, let's see:

  1. #! line first with good path and one arg max.,
  2. chmod,
  3. supporting environment from .profile or the like,
  4. cron running,
  5. cronab allowed to your id.

sorry but your message doesn't make much sense.

The script runs from command so its not a permissions. I have several scripts already running fine in cron.

[LEFT]Did you put a second line in each script, echoing out a debug message to a fixed path, so you can tell if cron runs either, say:

date "+%Y-%m-%d %H:%M:%S ($$) Start $0 ($#) $@" >>/tmp/croncheck.log

[/LEFT]

1 Like

no I dint but I will do now, run and get back to you..thanks.

Does syntax change for each line?

($$) Start S0 ($#) $@" >> /<filename>

Also check for core and email, and in the crontab line, maybe redirect to outer log

:5 4 3 2 1 (...) >>/var/tmp/cronlog.myid 2>&1

Here is my script

#!/usr/bin/sh

cd /home/it/capopt/APNRD/S30
files=`gdate -d today  +%-d_%-m_%Y`
newfiles=`gdate -d today  +%-d%m`
cat *"$files"* > robtest
sleep 20
#!/usr/bin/perl -w
cd /home/it/capopt/APNRD/S30
./hash.pl robtest > $newfiles
#kill $
exit 0

---------- Post updated at 09:36 AM ---------- Previous update was at 09:35 AM ----------

thanks I have also removed the redirects from cron

16 4 * * * /home/it/capopt/APNRD/S30/condenseS30.sh

That is two scripts, I hope, or what is the second #! for?

exit 0 is the free default implicitly, you just need it for other returns.

No, I meant put in the wrapper to collect any wandering output that occurs under cron. The () are only necessary if the are multiple commands on the line separated with ';'.

also I know the cron runs up to the execution of the

./hash.pl robtest > $newfiles

It is at this point it fails to run in cron. However from acommand line it runs without issue

---------- Post updated at 10:06 AM ---------- Previous update was at 10:04 AM ----------

i put the 2nd #! in for the reference to ./hash.pl robtest > $newfiles. Its all in 1 script!!!

apologies but Im still unclear as how to implelment these debug messages!

So, cron started the outer script OK, and is out of the picture.

In cron, you have not tty or environment. The closest interactive analog to cron is to run it under "rsh/rexec/remsh/ssh/ssh2 localhost <command>". You can even truss/tusc/strace in this mode: "rsh/rexec/remsh/ssh/ssh2 localhost truss -faelo /tmp/truss.tr <command>". You might need some environment (to test and to fix the problem). I have my ~/.profile set to support non-tty calls, by putting all the tty bits in one place, inside an "if [ `tty 2>&1` != 'not a tty' ] ; then". Then your <command> becomes ". $HOME/.profile;<command>" unless you do this inside "<command>".

Put logging in to ensure you get to that line, and test if you get past.

Anywhere you want to detect passing through, put:

date "+%Y-%m-%d %H:%M:%S ($$) $0 Line $LINENO" >>/tmp/croncheck.log
1 Like

Many thanks DGPickett but unfortunately you're pitching in above my head and Im kinda lost!

...That siad I will try and make sense of you last post!!!

just so you are clear

  • this script runs fine from command line
  • from cron it runs but doesnt get past the ./hash.pl robtest > $newfiles line

To emphasise what others have noticed, you cannot have two shebang lines in the same script. Only the shebang line on the very first line will be have any effect. The second shebang line is just a comment line but I don't think it matters.

./hash.pl robtest > $newfiles

This line is very dodgy for many reasons but to correct it we need to know what is in hash.pl and the full path to hash.pl .

see contents of hash.pl

#!/usr/bin/perl

##############################################################

#use strict;
use warnings;

my $hash = ();

sub trim($)
{
        my $string = shift;
        $string =~ s/^\s+//;
        $string =~ s/\s+$//;
        return $string;
}


#$target_filename = shift;
#open(SESAME,"<$target_filename") || die "Cannot open file for output\n";

while(<>){
        @fields = split(/\|/, $_);
        $msisdn = trim($fields[2]);
        $APNREQ = trim($fields[4]); if ($APNREQ eq "") { $APNREQ = "NULL"; }
        $APNSUB = trim($fields[5]);
        if($msisdn =~ /^353/){

        $msisdn .= "-$APNREQ";
        $msisdn .= "-$APNSUB";
        if (exists $hash{$msisdn}) {
        $num = $hash{$msisdn};
        $num++;
        delete $hash{$msisdn};
        $hash{ $msisdn } = $num;
        } else {

        $hash{ $msisdn } = '1';

        }

    }

}

while ( my ($key, $value) = each(%hash) ) {

@apns = split(/\-/, $key);

#print "$value " ."|" . "$apns[0]" . "|" . "$apns[1]" . "|" . "$apns[2]\n";
print "$value " ."|" ."$apns[0]" . "|" . "$apns[1]\n";

}