#57 Very low performance over network

open
nobody
None
5
2004-05-11
2004-05-11
ivan
No

Hi folks,

I tested GT.M over network and I experienced 20
times(!) slower performance than results of a one host
test.

The test code:
FOR I=1:1:1000 FOR J=1:1:100 FOR K=1:1:10 SET
^TSTVAR(I,J,K)=1

I used 33280 byte block size, 32767 byte record,
journaling. I used one remote server (gtcm_gnp_server).
The Global Directory was configured with the same
parameters in both machine (except the file name, of
course).

Client:
2,4 GHz P4
512 MB RAM
1 GBit Intel NIC

Server:
Dell 2600
Dual 2,8 Xeon
4 GB RAM
1 GBit NIC
36 GB U320 SCSI

(I made this test on another client with same
configuration, but the performance was dismally.)

The CPU utilization was low (about 6-15%), the network
utilization was low also (about 4Mbit).

Do you have any suggestion how can I inrease the
performance?

Thanks in advance,
ivan

Discussion

  • ivan
    ivan
    2004-05-11

    • summary: Very slow performance over network --> Very low performance over network
     
  • Logged In: YES
    user_id=97919

    Hi Ivan,

    With such a large block size, most of the "IO" on the local
    machine will be to the global buffer (in database shared
    memory) in RAM vs. two round trip network delays for the
    GT.CM option. I suspect almost all of the slowdown is due to
    the network access.

    Sorry but I do not have any more specific answers or
    suggestions for you.

    Thanks,
    Narayanan.

     
  • ivan
    ivan
    2004-05-12

    Logged In: YES
    user_id=1031262

    Hi Narayanan,

    So I would like to refine the test results: I experienced
    that my GT.M test program is 20 times faster if it uses
    database file directly than over TCP.

    I reduced the block and record size to the default values
    and I reran the tests, but the results are the same.

    So I made a new test, using the databyse over TCP, but the
    server and client was the same host.

    I got interesting results: sometimes the used network
    bandwidth was 1-3 Mbit and sometimes 40Mbit (over the
    loopback device), sometimes the network usage was 40Mbit at
    the begining of the test and than it falled back to 1-3
    Mbit. In most cases the speed was similar to the case when
    client and server was different hosts.

    Here is an strace summary of gtcm_gnp_server:
    % time seconds usecs/call calls errors syscall
    ------ ----------- ----------- --------- ---------
    ----------------
    68.09 12.292156 10 1256692
    rt_sigprocmask
    10.59 1.911213 11 179436 2 recv
    9.73 1.756979 10 179439 time
    6.23 1.124404 13 89719 sendmsg
    2.90 0.523025 6 89724 1 select
    2.08 0.375432 4 89719 2 rt_sigreturn
    0.25 0.045979 35 1331 pwrite
    0.02 0.003301 29 113 open
    0.02 0.002988 1494 2 fsync
    0.01 0.002636 23 113 read
    0.01 0.001622 5 339 fstat64
    0.01 0.001504 13 113 stat64
    0.01 0.001435 13 114 munmap
    0.01 0.001257 21 61 3 nanosleep
    0.01 0.001255 4 287 gettimeofday
    0.01 0.001137 10 114 pread
    0.01 0.000993 993 1 setup
    0.01 0.000952 8 113 mmap2
    0.01 0.000946 6 170 sched_yield
    0.00 0.000786 7 116 close
    0.00 0.000627 6 113 fstatfs
    0.00 0.000330 5 61 setitimer
    0.00 0.000239 4 57 2 sigreturn
    0.00 0.000201 101 2 shmctl
    0.00 0.000145 145 1 shmdt
    0.00 0.000025 5 5 semctl
    0.00 0.000016 5 3 recvmsg
    0.00 0.000013 7 2 semop
    ------ ----------- ----------- --------- ---------
    ----------------
    100.00 18.051596 1887960 10 total

    and a strace summary of client (it was made not the same run
    than the summary above):
    execve("/opt/gtm/mumps", ["/opt/gtm/mumps", "-r", "bigdb"],
    [/* 25 vars */]) = 0
    % time seconds usecs/call calls errors syscall
    ------ ----------- ----------- --------- ---------
    ----------------
    80.78 22.563225 226 100001 100001 rt_sigsuspend
    9.51 2.657098 7 400018
    rt_sigprocmask
    5.33 1.488301 7 200003 select
    1.93 0.539006 5 100003 sendmsg
    1.05 0.294083 3 100001 recvmsg
    0.77 0.213943 2 100003 100001 recv
    0.62 0.173930 2 100002 100001 rt_sigreturn
    0.00 0.000653 163 4 2 connect
    0.00 0.000379 6 63 33 open
    0.00 0.000225 6 35 read
    0.00 0.000214 4 49 29 stat64
    0.00 0.000181 2 83 3 rt_sigaction
    0.00 0.000164 4 38 old_mmap
    0.00 0.000110 3 34 close
    0.00 0.000110 7 15 munmap
    0.00 0.000070 23 3 readlink
    0.00 0.000067 2 32 fstat64
    0.00 0.000062 4 15 14 access
    0.00 0.000055 3 19 ioctl
    0.00 0.000042 11 4 socket
    0.00 0.000028 3 10 getcwd
    0.00 0.000028 4 8 mmap2
    0.00 0.000027 3 10 fcntl64
    0.00 0.000021 21 1 send
    0.00 0.000017 2 8 brk
    0.00 0.000012 6 2 mprotect
    0.00 0.000010 5 2 setsockopt
    0.00 0.000008 4 2 pread
    0.00 0.000007 2 3 uname
    0.00 0.000006 2 3 getpid
    0.00 0.000006 6 1 recvfrom
    0.00 0.000005 2 3 gettimeofday
    0.00 0.000005 3 2 _llseek
    0.00 0.000005 5 1 fstatfs64
    0.00 0.000002 2 1 1 unlink
    0.00 0.000002 2 1 time
    0.00 0.000002 2 1 getuid32
    0.00 0.000002 2 1 geteuid32
    0.00 0.000002 2 1
    set_thread_area
    0.00 0.000001 1 1 poll
    ------ ----------- ----------- --------- ---------
    ----------------
    100.00 27.932114 1100487 300085 total

    I will probe to make an strace output and summary when the
    client achive about 40 Mbit network usage. It may help.

    Have you some tips to improve the performane?

    Thanks in advance,
    ivan

     
  • ivan
    ivan
    2004-05-13

    Logged In: YES
    user_id=1031262

    I use linux kernel 2.6.6.

    I did some new tests. The database was configured the same
    than in my first tests (big blocks, etc.). The clients
    accessed the database over TCP. I used more clients.

    So my experiences:
    If I started a client on the host of the server it achieved
    about 40 Mbit over loopback interface.
    If I started a second client from another host, the network
    usage of first client decreased to about 6 Mbit and the
    network usage of second client was about 3-4Mbit (Overall
    network usage decreased to 9-10Mbit from 40Mbit!).
    If I started a new client on the host of the server (the
    second client on that host), that client used about 30Mbit
    over loopback interface. (The overall network useage
    increased again to about 40Mbit.)

    ivan

     
  • Steven Estes
    Steven Estes
    2004-05-13

    Logged In: YES
    user_id=97877

    Ivan,

    First off, thankyou for the interesting experiments and data.
    However, I do not have an explanation for the variation in
    processing speeds. Please forgive is some of this is above or
    below you as I do not know my audience.. :-)

    These deviations could be due to any of several causes.
    There are times when GTM runs very fast for awhile and most
    IO is to/from memory then the dreaded [ext3 especially] file
    sync timer goes off and suddenly everything crawls while a
    bunch of dirty pages get flushed to disk (GTM uses buffered
    database IO, only journal IO is hardened -- see admin and
    operations guide). So it could be physical IO that causes a
    drag effect. I've seen ext3 be especially susceptible to this.
    Maybe try reiserfs.

    I do not know how the loopback device is implemented in the
    kernel but so far as the (real) networking is concerned, it will
    never hold a candle to running GTM locally. When a program
    such as you described runs locally, most of it is going to do
    99% of both reads and writes directly to/from real memory.
    Until and unless your database is big enough to exceed your
    real storage in Linux, local runs will just run really really fast.
    That's the good news. There is no network existing that I
    know of that has the bandwidth or latency that is going to be
    anywhere close to this simple straight (shared) memory
    access where there are hardly any context switches.
    Network access is going to be substantially slower not only
    because of the transfer medium but because of the overhead
    of the message creation, parsing, etc. that is involved. It all
    adds up to latencies on both ends of the client<->server that
    slow the entire process down. BTW, I see you have Gigabit
    adapters on your boxes but you never said what the actual
    network was -- 10Mb, 100Mb, or 1Gb. If 100Mb, then the
    40Mb reading was actually pretty good, especially if it was a
    hub and not a switch which is another big difference.

    There is also the fact that the GTCM server has some design
    tradeoffs to portability with its VMS cousin versus unix/linux
    nativety that would make it run faster. It uses sigsuspend()
    and IO signals (SIGIO/SIGURG) in conjunction with select() to
    manage IO to mirror what the VMS implementation does with
    ASTs (asynchronous system trap) or interrupt handlers by
    another name. No doubt there are more efficient ways to
    implement communications but none that (easily) allow us to
    share the bulk of the server and client code between
    implementations. This may be looked at again in the future
    but for now it is what it is. The code is all part of the open
    source release so you are most welcome to look at it and
    make improvements. Send them to us if you wish (with a
    release as described on sourceforge) and we can see about
    encorporating them into a release..

    Hope this helps.

    Steve

     
  • ivan
    ivan
    2004-05-17

    Logged In: YES
    user_id=1031262

    Hi,

    I compiled a dbg version of GT.M (I modified the
    sr_unix_gnp/cmi_debug.c:22 GBLDEF int cmi_debug_enabled =
    FALSE; to GBLDEF int cmi_debug_enabled = TRUE;).

    I started the server and then I started a client on a
    different host and got the following:
    gtcm_gnp_server log:Mon May 17 12:54:17 2004 :
    /opt/gtm/gtcm_gnp_server
    -log=/opt/gtm/log/gtcm_server_11.log -service=6789 [pid : 5400]
    Enter cmj_handler signo = 29
    ENTER CMI_READ, AST 8053d88
    in cmj_clb_set_async sta = 1
    EXIT CMI_READ sta = 1
    Enter cmj_handler signo = 29
    in cmj_clb_reset_async sta = 1
    CALLING AST FROM CMJ_POSTEVENT after IODONE, called from 80cfcdd
    ENTER CMI_WRITE, AST 80571c4
    in cmj_clb_reset_async sta = 2
    EXIT CMI_WRITE sta = 0
    CALLING AST FROM CMJ_POSTEVENT after IODONE, called from 80cfcdd
    ENTER CMI_READ, AST 8053d88
    in cmj_clb_set_async sta = 1
    EXIT CMI_READ sta = 1
    Enter cmj_handler signo = 29
    in cmj_clb_reset_async sta = 1
    CALLING AST FROM CMJ_POSTEVENT after IODONE, called from 80cfcdd
    ENTER CMI_WRITE, AST 80571c4
    in cmj_clb_reset_async sta = 2
    EXIT CMI_WRITE sta = 0
    CALLING AST FROM CMJ_POSTEVENT after IODONE, called from 80cfcdd
    ENTER CMI_READ, AST 8053d88
    in cmj_clb_set_async sta = 1
    EXIT CMI_READ sta = 1
    Enter cmj_handler signo = 29
    in cmj_clb_reset_async sta = 1
    CALLING AST FROM CMJ_POSTEVENT after IODONE, called from 80cfcdd
    %GTM-F-ASSERT, Assert failed
    /home/ivan/downloads/GT.M/src/sr_port/db_csh_get.c line 71
    Mon May 17 13:00:10 2004: %GTM-F-ASSERT, Assert failed
    /home/ivan/downloads/GT.M/src/sr_port/t_ch.c line 69
    ENTER CMI_WRITE, AST 80571c4
    in cmj_clb_reset_async sta = 2
    EXIT CMI_WRITE sta = 0
    %GTM-E-SERVERERR, Severe error on server: %GTM-F-ASSERT,
    Assert failed /home/ivan/downloads/GT.M/src/sr_port/t_ch.c
    line 69

    the client wrote this:
    ENTER CMI_WRITE, AST 0
    in cmj_clb_reset_async sta = 2
    EXIT CMI_WRITE sta = 0
    ENTER CMI_READ, AST 0
    in cmj_clb_set_async sta = 1
    Enter cmj_handler signo = 29
    in cmj_clb_reset_async sta = 1
    EXIT CMI_READ sta = 0
    ENTER CMI_WRITE, AST 0
    in cmj_clb_reset_async sta = 2
    EXIT CMI_WRITE sta = 0
    ENTER CMI_READ, AST 0
    in cmj_clb_set_async sta = 1
    Enter cmj_handler signo = 29
    in cmj_clb_reset_async sta = 1
    EXIT CMI_READ sta = 0
    ENTER CMI_WRITE, AST 0
    in cmj_clb_reset_async sta = 2
    EXIT CMI_WRITE sta = 0
    ENTER CMI_READ, AST 0
    in cmj_clb_set_async sta = 1
    Enter cmj_handler signo = 29
    in cmj_clb_reset_async sta = 1
    EXIT CMI_READ sta = 0
    %GTM-E-SERVERERR, Severe error on server: %GTM-F-ASSERT,
    Assert failed /home/ivan/downloads/GT.M/src/sr_port/t_ch.c
    line 69
    At M source location +1^bigdb

    GTM>Enter cmj_handler signo = 29
    hENTER CMI_WRITE, AST 0
    in cmj_clb_reset_async sta = 2
    EXIT CMI_WRITE sta = 0

    gdb where output:
    #0 0x400a9561 in kill () from /lib/libc.so.6
    #1 0x08062042 in gtm_dump_core () at
    /home/ivan/downloads/GT.M/src/sr_unix/gtm_dump_core.c:55
    #2 0x08062479 in gtm_fork_n_core () at
    /home/ivan/downloads/GT.M/src/sr_unix/gtm_fork_n_core.c:161
    #3 0x08059a8d in ch_cond_core () at
    /home/ivan/downloads/GT.M/src/sr_unix/ch_cond_core.c:51
    #4 0x080880eb in rts_error (__builtin_va_alist=5) at
    /home/ivan/downloads/GT.M/src/sr_unix/rts_error.c:81
    #5 0x080c7d8d in t_ch (arg=-1073746720) at
    /home/ivan/downloads/GT.M/src/sr_port/t_ch.c:69
    #6 0x08088153 in rts_error (__builtin_va_alist=5) at
    /home/ivan/downloads/GT.M/src/sr_unix/rts_error.c:81
    #7 0x080b4b2b in db_csh_get (block=3) at
    /home/ivan/downloads/GT.M/src/sr_port/db_csh_get.c:71
    #8 0x08095217 in mm_update (cs=0x8143f20, cs_top=0x8143f88,
    ctn=3, effective_tn=3, si=0x0) at
    /home/ivan/downloads/GT.M/src/sr_unix/t_end_sysops.c:278
    #9 0x08094379 in t_end (hist1=0x8153c48, hist2=0x0) at
    /home/ivan/downloads/GT.M/src/sr_port/t_end.c:745
    #10 0x0807236b in gvcst_put_blk (v=0xbffff6c0,
    extra_block_split_req=0xbffff083 "") at
    /home/ivan/downloads/GT.M/src/sr_port/gvcst_put.c:1187
    #11 0x0806c61b in gvcst_put (v=0xbffff6c0) at
    /home/ivan/downloads/GT.M/src/sr_port/gvcst_put.c:115
    #12 0x08056263 in gtcmtr_put () at
    /home/ivan/downloads/GT.M/src/sr_port_cm/gtcmtr_put.c:102
    #13 0x08051ead in gtcm_gnp_server_actions () at
    /home/ivan/downloads/GT.M/src/sr_unix_gnp/gtcm_gnp_server.c:253
    #14 0x0805283d in main (argc=3, argv=0xbffffc54,
    envp=0xbffffc64) at
    /home/ivan/downloads/GT.M/src/sr_unix_gnp/gtcm_gnp_server.c:505

    The M client code:
    FOR I=1:1:10 FOR J=1:1:10 FOR K=1:1:10 SET ^TSTVAR1(I,J,K)=1

    Any idea?

    Thanks,
    ivan

     
  • Steven Estes
    Steven Estes
    2004-05-17

    Logged In: YES
    user_id=97877

    Ivan,

    From the stack trace below and from your earlier traces, it
    appears the database is using MM (mapped memory) mode
    access instead of BG (buffered global) mode access. We do
    not support MM mode on Unix. The MM mode support is
    incomplete and is known to have holes in it that can cause
    problems such as you are seeing. It may be completed at
    some point in the future but it is not a priority as it has not
    shown itself to be superior in any way to BG mode and in fact
    has several drawbacks. So please use BG mode for your
    testing.

    Steve