why cc "real time" >> "real time"?

Question

why cc "real time" >> "real time"?

I am having a problem with c compiler When compiling a simple hello world, user time is >>> real time.

Here the comparison of times between two machines.

It should be noted that the machine is not performing any other task, and the other operations run quickly (even other compilers)

MACHINE 1
$<stress> cc -xtime -# test.c
/opt/SUNWspro/bin/../SC5.0/bin/acomp -i test.c -y-fbe -y/opt/SUNWspro/bin/../SC5.0    /bin/fbe -y-xarch=v7 -y-o -ytest.o -y-s -y-verbose -Qy -D__SunOS_5_7 -D__SUNPRO_C=0x500 -D__SVR4 -D__unix -D__sun -D__sparc -D__BUILTIN_VA_ARG_INCR -Xa -D__PRAGMA_REDEFINE_EXTNAME -Dunix -Dsun -Dsparc -D__RESTRICT -I/opt/SUNWspro/SC5.0    /include/cc "-g/opt/SUNWspro/bin/../SC5.0/bin/cc -xtime -c "
acomp           real    0.1     user    0.0     sys     0.0
 Note: LD_LIBRARY_PATH = /opt/oracle/product/9.2.0/lib:/opt/SUNWspro/lib:/lib:    /usr/ccs/lib:/usr/openwin/lib:/usr/dt/lib
 Note: LD_RUN_PATH = <null>
/usr/ccs/bin/ld /opt/SUNWspro/SC5.0/lib/crti.o /opt/SUNWspro/SC5.0/lib/crt1.o     /opt/SUNWspro/SC5.0/lib/values-xa.o test.o -Y "P,/opt/SUNWspro/SC5.0/lib:/usr/ccs/lib:    /usr/lib" -Qy -lc /opt/SUNWspro/SC5.0/lib/crtn.o
linker        real    0.1     user    0.0     sys     0.0

MACHINE 1
stress$ cc -xtime -# test.c
/opt/SUNWspro/bin/../SC5.0/bin/acomp -i test.c -y-fbe -y/opt/SUNWspro/bin/../SC5.0/bin/fbe -y-xarch=v7 -y-o -ytest.o -y-s -y-verbose -Qy -D__SunOS_5_8 -D__SUNPRO_C=0x500 -D__SVR4 -D__unix -D__sun -D__sparc -D__BUILTIN_VA_ARG_INCR -Xa -D__PRAGMA_REDEFINE_EXTNAME -Dunix -Dsun -Dsparc -D__RESTRICT -I/opt/SUNWspro/SC5.0/include/cc "-g/opt/SUNWspro/bin/../SC5.0/bin/cc -xtime -c "
acomp           real 6:00.0     user    0.0     sys     0.0
 Note: LD_LIBRARY_PATH = /lib:/opt/oracle/product/7.3.4/lib:/opt/SUNWspro/lib:/usr/ccs/lib:/usr/ucblib:/usr/openwin/lib:/usr/dt/lib
 Note: LD_RUN_PATH = <null>
/usr/ccs/bin/ld /opt/SUNWspro/SC5.0/lib/crti.o /opt/SUNWspro/SC5.0/lib/crt1.o /opt/SUNWspro/SC5.0/lib/values-xa.o test.o -Y "P,/opt/SUNWspro/SC5.0/lib:/usr/ccs/lib:/usr/lib" -Qy -lc /opt/SUNWspro/SC5.0/lib/crtn.o
linker          real    0.3     user    0.0     sys     0.0

The compilation is done in the moment, but in the end in red is the compilation time ago wait with signal 20. That is where and then returns the prompt.

execve("/opt/SUNWspro/SC5.0/bin/cc", 0xFFBFF69C, 0xFFBFF6AC)  argc = 3
getuid()                                        = 1000 [1000]
getuid()                                        = 1000 [1000]
getgid()                                        = 1004 [1004]
getgid()                                        = 1004 [1004]
resolvepath("/usr/lib/ld.so.1", "/usr/lib/ld.so.1", 1023) = 16
open("/var/ld/ld.config", O_RDONLY)             = 3
fstat(3, 0xFFBFEEE8)                            = 0
mmap(0x00000000, 148, PROT_READ, MAP_SHARED, 3, 0) = 0xFF3E0000
close(3)                                        = 0
stat("/usr/lib/libc.so.1", 0xFFBFEF48)          = 0
resolvepath("/usr/lib/libc.so.1", "/usr/lib/libc.so.1", 1023) = 18
open("/usr/lib/libc.so.1", O_RDONLY)            = 3
mmap(0x00000000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xFF340000
mmap(0x00000000, 802816, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON, -1, 0) = 0xFF200000
mmap(0xFF200000, 703520, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF200000
mmap(0xFF2BC000, 24772, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 704512) = 0xFF2BC000
munmap(0xFF2AC000, 65536)                       = 0
memcntl(0xFF200000, 113528, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
close(3)                                        = 0
stat("/usr/lib/libdl.so.1", 0xFFBFEF48)         = 0
resolvepath("/usr/lib/libdl.so.1", "/usr/lib/libdl.so.1", 1023) = 19
open("/usr/lib/libdl.so.1", O_RDONLY)           = 3
mmap(0xFF340000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF340000
mmap(0x00000000, 8192, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON, -1, 0) = 0xFF330000
mmap(0xFF330000, 2638, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF330000
close(3)                                        = 0
stat("/usr/platform/SUNW,Sun-Fire-V890/lib/libc_psr.so.1", 0xFFBFEC68) = 0
resolvepath("/usr/platform/SUNW,Sun-Fire-V890/lib/libc_psr.so.1", "/usr/platform/sun4u-us3/lib/libc_psr.so.1", 1023) = 41
open("/usr/platform/SUNW,Sun-Fire-V890/lib/libc_psr.so.1", O_RDONLY) = 3
mmap(0xFF340000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF340000
close(3)                                        = 0
mmap(0x00000000, 8192, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFF320000
dup(0)                                          = 3
llseek(0, 0, SEEK_CUR)                          = 749366
close(0)                                        = 0
fcntl(3, F_DUP2FD, 0x00000000)                  = 0
close(3)                                        = 0
dup(1)                                          = 3
close(1)                                        = 0
fcntl(3, F_DUP2FD, 0x00000001)                  = 1
close(3)                                        = 0
dup(2)                                          = 3
close(2)                                        = 0
fcntl(3, F_DUP2FD, 0x00000002)                  = 2
close(3)                                        = 0
sys#177(0x00000080, 0xFFBFF47C, 0xFF3F0500, 0x00000000, 0xFF3C2EF8, 0xFF2C0284) = 0x00000000 [0xFFBFF47C]
sys#227(0x00000006, 0x00000000, 0x0001ADFC, 0xFF3F0500, 0xFF3C3C18, 0xFF3C2670) = 0x00000009 [0x00000000]
sys#227(0x00000002, 0x00000009, 0x0000000E, 0xFFBFF5AE, 0x00000002, 0xFF3C2670) = 0x00000002 [0x00000000]
sys#177(0x00000001, 0xFFBFF508, 0x73797364, 0x6363002D, 0x00000002, 0xFF3C2670) = 0x00000000 [0xFFBFF508]
open("/.machine", O_RDONLY)                     Err#2 ENOENT
sys#177(0x00000003, 0xFFBFF4EC, 0x73797364, 0x6363002D, 0x00000002, 0xFF3C2670) = 0x00000000 [0xFFBFF4EC]
getuid()                                        = 1000 [1000]
getuid()                                        = 1000 [1000]
getgid()                                        = 1004 [1004]
getgid()                                        = 1004 [1004]
resolvepath("/usr/lib/ld.so.1", "/usr/lib/ld.so.1", 1023) = 16
open("/var/ld/ld.config", O_RDONLY)             = 3
fstat(3, 0xFFBFEEE8)                            = 0
mmap(0x00000000, 148, PROT_READ, MAP_SHARED, 3, 0) = 0xFF310000
close(3)                                        = 0
stat("/usr/lib/secure/s8_preload.so.1", 0xFFBFF020) = 0
resolvepath("/usr/lib/secure/s8_preload.so.1", "/.SUNWnative/usr/lib/brand/solaris8/s8_preload.so.1", 1023) = 51
open("/usr/lib/secure/s8_preload.so.1", O_RDONLY) = 3
mmap(0x00000000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xFF300000
mmap(0x00002000, 81920, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON, -1, 0) = 0xFF2E0000
mmap(0xFF2E0000, 920, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF2E0000
mmap(0xFF2F2000, 272, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 8192) = 0xFF2F2000
munmap(0xFF2E2000, 65536)                       = 0
memcntl(0xFF2E0000, 736, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
close(3)                                        = 0
stat("/opt/oracle/product/7.3.4/lib/libc.so.1", 0xFFBFEF48) Err#2 ENOENT
stat("/usr/lib/libc.so.1", 0xFFBFEF48)          = 0
resolvepath("/usr/lib/libc.so.1", "/usr/lib/libc.so.1", 1023) = 18
open("/usr/lib/libc.so.1", O_RDONLY)            = 3
mmap(0xFF300000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF300000
mmap(0x00000000, 802816, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON, -1, 0) = 0xFF100000
mmap(0xFF100000, 703520, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF100000
mmap(0xFF1BC000, 24772, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 704512) = 0xFF1BC000
munmap(0xFF1AC000, 65536)                       = 0
memcntl(0xFF100000, 113528, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
close(3)                                        = 0
stat("/opt/oracle/product/7.3.4/lib/libdl.so.1", 0xFFBFEF48) Err#2 ENOENT
stat("/usr/lib/libdl.so.1", 0xFFBFEF48)         = 0
resolvepath("/usr/lib/libdl.so.1", "/usr/lib/libdl.so.1", 1023) = 19
open("/usr/lib/libdl.so.1", O_RDONLY)           = 3
mmap(0xFF300000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF300000
mmap(0x00000000, 8192, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON, -1, 0) = 0xFF2D0000
mmap(0xFF2D0000, 2638, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF2D0000
close(3)                                        = 0
mmap(0x00000000, 8192, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFF2B0000
stat("/usr/platform/SUNW,Sun-Fire-V890/lib/libc_psr.so.1", 0xFFBFEC68) = 0
resolvepath("/usr/platform/SUNW,Sun-Fire-V890/lib/libc_psr.so.1", "/usr/platform/sun4u-us3/lib/libc_psr.so.1", 1023) = 41
open("/usr/platform/SUNW,Sun-Fire-V890/lib/libc_psr.so.1", O_RDONLY) = 3
mmap(0xFF300000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFF300000
close(3)                                        = 0
sys#229(0x00046ED8, 0x00000400)                 = 0x00000000 [0x00000400]
brk(0x000477D0)                                 = 0
brk(0x000497D0)                                 = 0
stat("/opt/oracle/product/7.3.4/bin/cc", 0xFFBFEC28) Err#2 ENOENT
stat("/appl/prod/siscel/util/cc", 0xFFBFEC28)   Err#2 ENOENT
stat("/solaris7/usr/ccs/bin/cc", 0xFFBFEC28)    Err#2 ENOENT
stat("/opt/SUNWspro/bin/cc", 0xFFBFEC28)        = 0
readlink("/opt/SUNWspro/bin/cc", "../SC5.0/bin/cc", 1024) = 15
readlink("/opt/SUNWspro/bin/../SC5.0/bin/cc", 0xFFBFED14, 1024) Err#22 EINVAL
open("/opt/SUNWspro/bin/../SC5.0/bin/../lib/locale/C/LC_MESSAGES/SUNW_SPRO_SC_cc.cat", O_RDONLY) Err#2 ENOENT
open("/opt/SUNWspro/bin/../SC5.0/bin/../../lib/locale/C/LC_MESSAGES/SUNW_SPRO_SC_cc.cat", O_RDONLY) Err#2 ENOENT
lwp_sigtimedwait(0xFFBFF518, 0xFFBFF3D8, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF3E0, 0xFFBFF308, 0x00000010) = 0
sysconfig(_CONFIG_SIGRT_MIN)                    = 41
sysconfig(_CONFIG_SIGRT_MAX)                    = 48
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3E0, 0x00000010) = 0
sigaction(SIGHUP, 0xFFBFF3D8, 0xFFBFF3B0)       = 0
lwp_sigtimedwait(0xFFBFF3B8, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3B8, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF3B0, 0xFFBFF598, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF518, 0xFFBFF3D8, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF3E0, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3E0, 0x00000010) = 0
sigprocmask(SIG_BLOCK, 0xFFBFF3A0, 0xFFBFF388)  = 0
sigaction(SIGHUP, 0xFFBFF3D8, 0xFFBFF3B0)       = 0
lwp_sigtimedwait(0xFFBFF3B8, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3B8, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF3B0, 0xFFBFF598, 0x00000020) = 0
sigprocmask(SIG_SETMASK, 0xFFBFF388, 0x00000000) = 0
lwp_sigtimedwait(0xFFBFF518, 0xFFBFF3D8, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF3E0, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3E0, 0x00000010) = 0
sigaction(SIGINT, 0xFFBFF3D8, 0xFFBFF3B0)       = 0
lwp_sigtimedwait(0xFFBFF3B8, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3B8, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF3B0, 0xFFBFF598, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF518, 0xFFBFF3D8, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF3E0, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3E0, 0x00000010) = 0
sigprocmask(SIG_BLOCK, 0xFFBFF3A0, 0xFFBFF388)  = 0
sigaction(SIGINT, 0xFFBFF3D8, 0xFFBFF3B0)       = 0
lwp_sigtimedwait(0xFFBFF3B8, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3B8, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF3B0, 0xFFBFF598, 0x00000020) = 0
sigprocmask(SIG_SETMASK, 0xFFBFF388, 0x00000000) = 0
lwp_sigtimedwait(0xFFBFF518, 0xFFBFF3D8, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF3E0, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3E0, 0x00000010) = 0
sigaction(SIGTERM, 0xFFBFF3D8, 0xFFBFF3B0)      = 0
lwp_sigtimedwait(0xFFBFF3B8, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3B8, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF3B0, 0xFFBFF598, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF518, 0xFFBFF3D8, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF3E0, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3E0, 0x00000010) = 0
sigprocmask(SIG_BLOCK, 0xFFBFF3A0, 0xFFBFF388)  = 0
sigaction(SIGTERM, 0xFFBFF3D8, 0xFFBFF3B0)      = 0
lwp_sigtimedwait(0xFFBFF3B8, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3B8, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF3B0, 0xFFBFF598, 0x00000020) = 0
sigprocmask(SIG_SETMASK, 0xFFBFF388, 0x00000000) = 0
lwp_sigtimedwait(0xFFBFF518, 0xFFBFF3D8, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF3E0, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3E0, 0x00000010) = 0
sigaction(SIGPIPE, 0xFFBFF3D8, 0xFFBFF3B0)      = 0
lwp_sigtimedwait(0xFFBFF3B8, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3B8, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF3B0, 0xFFBFF598, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF518, 0xFFBFF3D8, 0x00000020) = 0
lwp_sigtimedwait(0xFFBFF3E0, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3E0, 0x00000010) = 0
sigprocmask(SIG_BLOCK, 0xFFBFF3A0, 0xFFBFF388)  = 0
sigaction(SIGPIPE, 0xFFBFF3D8, 0xFFBFF3B0)      = 0
lwp_sigtimedwait(0xFFBFF3B8, 0xFFBFF308, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF2F8, 0xFFBFF3B8, 0x00000010) = 0
lwp_sigtimedwait(0xFFBFF3B0, 0xFFBFF598, 0x00000020) = 0
sigprocmask(SIG_SETMASK, 0xFFBFF388, 0x00000000) = 0
brk(0x000497D0)                                 = 0
brk(0x0004B7D0)                                 = 0
uname(0xFFBFEAA8)                               = 1
lwp_sigtimedwait(0xFFBFEAA8, 0xFFBFF0D0, 0x00000505) = 0
fork()                                          = 10196
wait()                          (sleeping...)
    Received signal #20, SIGWINCH, in wait() [default]
      siginfo: SIG#0
    Received signal #20, SIGWINCH, in wait() [default]
      siginfo: SIG#0
wait()                          (sleeping...)
wait()                                          = 10196 [0x0000]
llseek(0, 0, SEEK_CUR)                          = 757598
_exit(0)

Any idea where to look?

c

compiler-construction

solaris

cc

asked on Stack Overflow Mar 22, 2012 by

caeycae

1 Answer

Real time (i.e. wall clock time) is always larger than the sum of user (application) and system (OS) time.

There is no CPU usage when the program is doing input/output operations and obviously, compiling is something that needs a lot of I/Os.

answered on Stack Overflow Mar 24, 2012 by

jlliagre

User contributions licensed under CC BY-SA 3.0