This discussion is archived
8 Replies Latest reply: Dec 21, 2011 1:18 AM by 902588 RSS

slave's write bytes is much higher than master's

901526 Newbie
Currently Being Moderated
i m using bdb 4.8.30, to make a one master-one slave replication benchmark test. my test is quite simple, use apache ab tools to run a php to call bdb api to write.

The problem i faced is that slave's write bytes/s is much more than master's write bytes, i used dstat or iostat to watch it, and the master's wbps is average 20M while the slave's wbps already over 80M.

the sync mode i set is DB_REPMGR_ACKS_ONE_PEER and when i changed it to DB_REPMGR_ACKS_NONE, the slave's wbps is still very high, what is the worse, after ab test stopped, the master's wbps go down immediately but slave's wbps still keep high for quite a while, my master and slave is in the same lan area.

what's wrong whit it? Did i make something wrong?
  • 1. Re: slave's write bytes is much higher than master's
    Paula B Explorer
    Currently Being Moderated
    It is difficult for us to know what replication is doing based on your description. What exactly are you measuring with dstat or iostat? Are you measuring the devices containing the BDB databases? The BDB logs? The BDB environment home directory? Are there other things happening on the system at the same time that might also be causing writes to the devices you are measuring?

    Here are some questions to help us understand what your test is doing:

    1. What priority have you set your slave to? If you set it to 0 to make it unelectable, there is no difference between the ACKS_NONE and ACKS_ONE_PEER policies.
    2. When you stop your test, do you actually shut down your master or simply stop writing to it?
    3. When you start your test, is there already a large existing database at the master? Does the slave already have a database synchronized with the master or does it have a new/empty database?

    If you can provide replication statistics output from a test run, it will give us more clues about what replication is doing:

    1. Set up to run your test again
    2. Collect "db_stat -r" output from both your master and slave
    3. Run your test
    4. Collect "db_stat -r" output from both your master and slave again

    Please keep in mind that this week is a US holiday and you might not see further replies until next week.

    Paula Bingham
    Oracle
  • 2. Re: slave's write bytes is much higher than master's
    902588 Newbie
    Currently Being Moderated
    ENVIRONMENT:
    A network program which we called mcdb is based on BDB 4.8.30. It is used to accept get/set requests and then query data from bdb or save data to bdb.
    mcdb implements replication with bdb replication manager api. The default start replication policy is DB_REP_ELECTION, rep ack policy is DB_REPMGR_ACKS_ONE_PEER and rep priority is 100.
    The bdb data files, bdb log files, region files and rep files are all in the same home directory.
    In addition, DB_TXN_WRITE_NOSYNC is used.
    There are two instances of the mcdb are separately on two standalone servers which has no other programs. These two instances are in one replication group which can elect a master automatically.
    A network client program is used to start requests to mcdb. In our benchmark test, a php program is as the network client program and we use ab (apache stress test tools) to start a mass of requests.

    ACTIONS:
    1. Start two mcdb instances on two servers and the two instance make a replication group. Start apache process in the 3rd machine and copy the php test script in the htdocs of the apache.
    2. db_stat -r (see the result as follows)
    3. start test (use ab to produce a mass of request) : ab -n 1000 -c 100 http://127.0.0.1/test.php
    4. db_stat -r (see the result as follows)

    RESULT:
    1. Slave has already synchronized with the master.
    2. The disk write(Bytes/s) of slave is much more than master, and the outputs of dstat are as follows:

    Master:
    ----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system--
    usr sys idl wai hiq siq| read writ| recv send| in out | int csw
    1 0 96 3 0 0| 328k 1048k| 441k 678k| 0 0 |2828 3989
    0 0 97 2 0 0| 312k 4976k| 472k 727k| 0 0 |2745 3917
    1 0 96 3 0 0| 320k 1048k| 515k 784k| 0 0 |3481 4999
    1 0 97 2 0 0| 272k 18M|4727k 13M| 0 0 |3452 3959
    0 0 97 1 0 0| 344k 216k| 516k 801k| 0 0 |3142 4252
    0 1 96 2 0 0| 192k 60M| 516k 814k| 0 0 |2147 3474
    1 1 96 3 0 0| 256k 18M| 290k 433k| 0 0 |3738 4372
    0 0 97 3 0 0| 312k 136k|4687k 13M| 0 0 |2508 3673
    1 1 95 3 0 1| 296k 11M| 470k 715k| 0 0 |4065 4773
    0 0 96 3 0 0| 328k 8816k|4795k 14M| 0 0 |2925 3951
    0 0 97 2 0 0| 320k 8192B| 480k 744k| 0 0 |2732 3889
    1 1 96 2 0 0| 328k 34M|3480k 820k| 0 0 |4123 4640
    0 0 97 3 0 0| 288k 1568k|1766k 13M| 0 0 |2392 3566
    1 1 95 2 0 1| 584k 18M|4703k 5131k| 0 0 |4293 4874
    0 0 96 3 0 0| 656k 1680k| 587k 9712k| 0 0 |2763 3919
    1 0 95 3 0 0| 856k 5792k| 505k 849k| 0 0 |3529 6086
    1 0 94 4 0 0| 336k 22M| 613k 780k| 0 0 |3125 4148

    Slave:
    ----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system--
    usr sys idl wai hiq siq| read writ| recv send| in out | int csw
    1 0 96 3 0 0| 368k 10M| 701k 59k| 0 0 |2987 14k
    3 1 93 2 0 1| 360k 27M|5045k 94k| 0 0 |3580 16k
    1 0 96 3 0 0| 336k 12M|5375k 339k| 0 0 |3239 15k
    1 1 95 3 0 0| 448k 21M| 859k 70k| 0 0 |3226 15k
    1 1 86 12 0 0| 176k 66M| 343k 83k| 0 0 |2385 8575
    3 1 93 3 0 1| 312k 25M|9483k 119k| 0 0 |3730 13k
    1 0 96 3 0 0| 320k 11M| 654k 252k| 0 0 |3034 14k
    3 1 94 2 0 1| 360k 27M|9553k 347k| 0 0 |4211 16k
    1 0 96 3 0 0| 376k 18M| 698k 56k| 0 0 |3098 14k
    2 1 95 3 0 0| 368k 20M| 751k 95k| 0 0 |3408 16k
    1 1 95 3 0 0| 328k 18M|9480k 91k| 0 0 |3250 15k
    2 1 95 3 0 0| 336k 18M| 615k 62k| 0 0 |3214 14k
    2 1 95 2 0 0| 392k 20M|9612k 127k| 0 0 |3518 16k
    1 0 96 3 0 0| 336k 12M| 709k 48k| 0 0 |2943 14k
    1 0 97 2 0 0| 304k 11M| 770k 60k| 0 0 |2994 15k
    1 0 96 2 0 0| 360k 11M| 819k 87k| 0 0 |2995 15k
    1 0 96 2 0 0| 376k 12M| 706k 76k| 0 0 |3258 16k
    1 0 97 2 0 0| 384k 11M| 840k 110k| 0 0 |3143 15k
  • 3. Re: slave's write bytes is much higher than master's
    902588 Newbie
    Currently Being Moderated
    The db_stat result of Action 2:

    ====================MASTER==========================
    0 Number of PERM messages not acknowledged
    0 Number of messages queued due to network delay
    0 Number of messages discarded due to queue length
    0 Number of existing connections dropped
    2 Number of failed new connection attempts
    =-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
    DB_REPMGR site information:
    10.67.15.147 (eid: 0, port: 30555)
    Environment configured as a replication master
    347/9070431 Next LSN to be used
    0/0 Not waiting for any missed log records
    0/0 No maximum permanent LSN
    0 Next page number expected
    0 Not waiting for any missed pages
    0 Number of duplicate master conditions originally detected at this site
    2147M Current environment ID (2147483647)
    100 Current environment priority
    13 Current generation number
    14 Election generation number for the current or next election
    0 Number of duplicate log records received
    0 Number of log records currently queued
    0 Maximum number of log records ever queued at once
    0 Total number of log records queued
    0 Number of log records received and appended to the log
    0 Number of log records missed and requested
    2147M Current master ID (2147483647)
    1 Number of times the master has changed
    0 Number of messages received with a bad generation number
    6 Number of messages received and processed
    0 Number of messages ignored due to pending recovery
    0 Number of failed message sends
    15 Number of messages sent
    0 Number of new site messages received
    2 Number of environments believed to be in the replication group
    0 Transmission limited
    0 Number of outdated conditions detected
    0 Number of duplicate page records received
    0 Number of page records received and added to databases
    0 Number of page records missed and requested
    Startup incomplete
    0 Number of transactions applied
    0 Number of startsync messages delayed
    1 Number of elections held
    1 Number of elections won
    No election in progress
    5.023795 Duration of last election (seconds)
    0 Number of bulk buffer sends triggered by full buffer
    0 Number of single records exceeding bulk buffer size
    0 Number of records added to a bulk buffer
    0 Number of bulk buffers sent
    0 Number of re-request messages received
    0 Number of request messages this client failed to process
    0 Number of request messages received by this client
    =================MASTER==================

    =================SLAVE===================
    0 Number of PERM messages not acknowledged
    0 Number of messages queued due to network delay
    0 Number of messages discarded due to queue length
    0 Number of existing connections dropped
    0 Number of failed new connection attempts
    =-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
    DB_REPMGR site information:
    10.67.15.146 (eid: 0, port: 30555)
    Environment configured as a replication client
    347/9070431 Next LSN expected
    0/0 Not waiting for any missed log records
    347/9070303 Maximum permanent LSN
    0 Next page number expected
    0 Not waiting for any missed pages
    0 Number of duplicate master conditions originally detected at this site
    2147M Current environment ID (2147483647)
    100 Current environment priority
    13 Current generation number
    14 Election generation number for the current or next election
    1 Number of duplicate log records received
    0 Number of log records currently queued
    2 Maximum number of log records ever queued at once
    2 Total number of log records queued
    2 Number of log records received and appended to the log
    0 Number of log records missed and requested
    0 Current master ID
    1 Number of times the master has changed
    0 Number of messages received with a bad generation number
    10 Number of messages received and processed
    0 Number of messages ignored due to pending recovery
    0 Number of failed message sends
    8 Number of messages sent
    0 Number of new site messages received
    0 Number of environments believed to be in the replication group
    0 Transmission limited
    0 Number of outdated conditions detected
    0 Number of duplicate page records received
    0 Number of page records received and added to databases
    0 Number of page records missed and requested
    Startup complete
    0 Number of transactions applied
    0 Number of startsync messages delayed
    0 Number of elections held
    0 Number of elections won
    No election in progress
    0 Number of bulk buffer sends triggered by full buffer
    0 Number of single records exceeding bulk buffer size
    0 Number of records added to a bulk buffer
    0 Number of bulk buffers sent
    0 Number of re-request messages received
    0 Number of request messages this client failed to process
    0 Number of request messages received by this client
    ================SLAVE====================

    Edited by: 899585 on 2011-11-28 下午3:52
  • 4. Re: slave's write bytes is much higher than master's
    902588 Newbie
    Currently Being Moderated
    The db_stat result of Action 4:

    ================MASTER================
    17 Number of PERM messages not acknowledged
    0 Number of messages queued due to network delay
    0 Number of messages discarded due to queue length
    0 Number of existing connections dropped
    2 Number of failed new connection attempts
    =-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
    DB_REPMGR site information:
    10.67.15.147 (eid: 0, port: 30555)
    Environment configured as a replication master
    351/8401941 Next LSN to be used
    0/0 Not waiting for any missed log records
    0/0 No maximum permanent LSN
    0 Next page number expected
    0 Not waiting for any missed pages
    0 Number of duplicate master conditions originally detected at this site
    2147M Current environment ID (2147483647)
    100 Current environment priority
    13 Current generation number
    14 Election generation number for the current or next election
    0 Number of duplicate log records received
    0 Number of log records currently queued
    0 Maximum number of log records ever queued at once
    0 Total number of log records queued
    0 Number of log records received and appended to the log
    0 Number of log records missed and requested
    2147M Current master ID (2147483647)
    1 Number of times the master has changed
    0 Number of messages received with a bad generation number
    6 Number of messages received and processed
    0 Number of messages ignored due to pending recovery
    17 Number of failed message sends
    106688 Number of messages sent
    0 Number of new site messages received
    2 Number of environments believed to be in the replication group
    0 Transmission limited
    0 Number of outdated conditions detected
    0 Number of duplicate page records received
    0 Number of page records received and added to databases
    0 Number of page records missed and requested
    Startup incomplete
    0 Number of transactions applied
    0 Number of startsync messages delayed
    1 Number of elections held
    1 Number of elections won
    No election in progress
    5.023795 Duration of last election (seconds)
    0 Number of bulk buffer sends triggered by full buffer
    0 Number of single records exceeding bulk buffer size
    0 Number of records added to a bulk buffer
    0 Number of bulk buffers sent
    0 Number of re-request messages received
    0 Number of request messages this client failed to process
    0 Number of request messages received by this client
    ================MASTER================

    ================SLAVE================
    0 Number of PERM messages not acknowledged
    0 Number of messages queued due to network delay
    0 Number of messages discarded due to queue length
    0 Number of existing connections dropped
    0 Number of failed new connection attempts
    =-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
    DB_REPMGR site information:
    10.67.15.146 (eid: 0, port: 30555)
    Environment configured as a replication client
    351/8401941 Next LSN expected
    0/0 Not waiting for any missed log records
    351/8401885 Maximum permanent LSN
    0 Next page number expected
    0 Not waiting for any missed pages
    0 Number of duplicate master conditions originally detected at this site
    2147M Current environment ID (2147483647)
    100 Current environment priority
    13 Current generation number
    14 Election generation number for the current or next election
    1 Number of duplicate log records received
    0 Number of log records currently queued
    16 Maximum number of log records ever queued at once
    4146 Total number of log records queued
    106684 Number of log records received and appended to the log
    0 Number of log records missed and requested
    0 Current master ID
    1 Number of times the master has changed
    0 Number of messages received with a bad generation number
    106700 Number of messages received and processed
    0 Number of messages ignored due to pending recovery
    0 Number of failed message sends
    8 Number of messages sent
    0 Number of new site messages received
    0 Number of environments believed to be in the replication group
    0 Transmission limited
    0 Number of outdated conditions detected
    0 Number of duplicate page records received
    0 Number of page records received and added to databases
    0 Number of page records missed and requested
    Startup complete
    20628 Number of transactions applied
    0 Number of startsync messages delayed
    0 Number of elections held
    0 Number of elections won
    No election in progress
    0 Number of bulk buffer sends triggered by full buffer
    0 Number of single records exceeding bulk buffer size
    0 Number of records added to a bulk buffer
    0 Number of bulk buffers sent
    0 Number of re-request messages received
    0 Number of request messages this client failed to process
    0 Number of request messages received by this client
    ================SLAVE================
  • 5. Re: slave's write bytes is much higher than master's
    Paula B Explorer
    Currently Being Moderated
    Thank you for providing the replication stat output we requested and the other details about your application and its settings. It was also quite useful to see the dstat output.

    We think the significant factor here is that you are using DB_TXN_WRITE_NOSYNC instead of DB_TXN_NOSYNC. This is likely causing some additional log flushes on the client that do not occur on the master. We think use of DB_TXN_NOSYNC would prevent these additional log flushes on the client. Would it be possible for your application to use DB_TXN_NOSYNC?

    Even if it is not possible for your application to switch permanently to DB_TXN_NOSYNC, can you temporarily make this change and rerun your test and let us know if it reduces the extra client writes? This would help confirm our theory.

    Thanks,
    Paula Bingham
    Oracle
  • 6. Re: slave's write bytes is much higher than master's
    902588 Newbie
    Currently Being Moderated
    Thank you very much for your repling our question.

    I think your theory is right, and client writes is lower if using DB_TXN_NOSYNC instead of DB_TXN_WRITE_NOSYNC.

    If we use DB_TXN_NOSYNC instead of DB_TXN_WRITE_NOSYNC, when the process is crash, will the data which has been written but not flush to disk be safe? May we lose data?

    Another question: if the flag DB_LOG_IN_MEMORY is set, synchronization from client to master may be suspended sometimes. I set a key/value to master successfully and can not get the key/value from client. Now I use db_stat to get the stats from client, some error occurs and error message is as follows:
    db_stat: PANIC: fatal region error detected; run recovery
    db_stat: DB_ENV->open: /data0/mdb/20111/: DB_RUNRECOVERY: Fatal error, run database recovery
    Why?

    Thanks,
  • 7. Re: slave's write bytes is much higher than master's
    Paula B Explorer
    Currently Being Moderated
    If we use DB_TXN_NOSYNC instead of DB_TXN_WRITE_NOSYNC, when the process is crash, will the data which has been written but not flush to disk be safe? May we lose data?
    Both DB_TXN_NOSYNC and DB_TXN_WRITE_NOSYNC sacrifice durability for performance, so you risk losing some committed transactions during a recovery with either option. With DB_TXN_NOSYNC, you risk losing more committed transactions and the number you lose depends on how many updates can fit into the log buffer.

    Another question: if the flag DB_LOG_IN_MEMORY is set, synchronization from client to master may be suspended sometimes. I set a key/value to master successfully and can not get the key/value from client. Now I use db_stat to get the stats from client, some error occurs and error message is as follows:
    db_stat: PANIC: fatal region error detected; run recovery
    db_stat: DB_ENV->open: /data0/mdb/20111/: DB_RUNRECOVERY: Fatal error, run database recovery
    Why?
    This sounds like you have hit a failure before you try to get stats. I will likely need to see what happens right before the client stops getting updates to see what is wrong.

    If you can reproduce this easily, would it be possible for you to post or send me the full verbose output from a case where the client stops getting updates? My email is in the standard firstname.lastname@oracle.com format. You get full verbose output by calling DB_ENV->set_verbose() with the DB_VERB_REPLICATION flag.

    If the full verbose output is prohibitive, the diag files provide a subset of the full verbose information and are enabled by default. They are the __db.rep.diag00 and __db.rep.diag01 files in the env home directory.

    Paula Bingham
    Oracle
  • 8. Re: slave's write bytes is much higher than master's
    902588 Newbie
    Currently Being Moderated
    I cannot reprodece that fault. Some of my operation may be wrong. If the problem is reappear, I'll contact you again.

    It is very kind of you to help us! Thank you so much!

    BRs,
    simpcl

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points