3 Replies Latest reply on Oct 11, 2013 9:15 PM by Henk Vandenbergh-Oracle

    Vdbench 503, ran into the following issu.

    d932efcf-6412-41b0-b9b6-b8aef51e8f93

      Hi,

       

      I am using Vdbench 503, linux.

      When I run one case, it reports the following error info and the case can't start (but when I run some other cases or run the same issue on another server, no this issue).

      Would you like to help me on this? What should I do to fix it?

       

      THanks,

      May

       

      Vdbench distribution: vdbench503
      For documentation, see 'vdbench.pdf'.

      12:55:20.282 Created output directory '/root/nvme/vdbench503/ppp001'
      12:55:20.296 input argument scanned: '-oppp+'
      12:55:20.296 input argument scanned: '-d25'
      12:55:20.296 input argument scanned: '-v'
      12:55:20.297 input argument scanned: '-f./vd_ds_dv.vd'
      12:55:20.458 Starting slave: /root/nvme/vdbench503/vdbench SlaveJvm -m localhost -n localhost-10-131011-12.55.20.259 -l localhost-0 -p 5570  -d25
      12:55:20.829 All slaves are now connected
      12:55:51.346 Waiting for slave synchronization: localhost-0
      12:56:21.801 Waiting for slave synchronization: localhost-0
      12:56:51.753 Waiting for slave synchronization: localhost-0
      12:57:21.935 Waiting for slave synchronization: localhost-0
      12:57:51.677 Waiting for slave synchronization: localhost-0
      12:58:21.638 Waiting for slave synchronization: localhost-0
      12:58:51.882 Waiting for slave synchronization: localhost-0
      12:59:21.707 Waiting for slave synchronization: localhost-0
      12:59:52.267 Waiting for slave synchronization: localhost-0
      13:00:21.920 Waiting for slave synchronization: localhost-0
      13:00:29.882
      13:00:29.965 Receiving unexpected EOFException from slave: localhost-0
      13:00:29.966 This means that this slave terminated prematurely.
      13:00:30.056 This thread will go to sleep for 5 seconds to allow
      13:00:30.056 slave termination to be properly recognized.
      13:00:30.056
      13:00:31.104
      13:00:31.148 Slave localhost-0 prematurely terminated.
      13:00:31.272 Look at file localhost-0.stdout.html for more information.
      13:00:31.272
      13:00:31.272 Slave localhost-0 prematurely terminated.
      13:00:31.273
      java.lang.RuntimeException: Slave localhost-0 prematurely terminated.
              at Vdb.common.failure(common.java:291)
              at Vdb.SlaveStarter.startSlave(SlaveStarter.java:179)
              at Vdb.SlaveStarter.run(SlaveStarter.java:50)

        • 1. Re: Vdbench 503, ran into the following issu.
          Henk Vandenbergh-Oracle

          See 'Look at file localhost-0.stdout.html for more information.' above.

          Did you find anything useful there?

          • 2. Re: Vdbench 503, ran into the following issu.
            d932efcf-6412-41b0-b9b6-b8aef51e8f93

            Hi,

             

            I am really appreciated for your help. Thank you very much!

             

            1) I copy my script here.

            data_error=(1,10)

            hd=localhost, jvms=1

            sd=sd1,lun=/dev/nvme0n1,range=(0,100),size=750g,threads=256,hitarea=0,openflags=o_direct

            wd=wd1,sd=sd1,rdpct=0,xf=1024k,seekpct=eof

            rd=rd0,wd=wd1,iorate=max,elapsed=300,xf=4k,rdpct=0,seekpct=100,interval=1

            rd=rd2,sd=sd1,iorate=10000,elapsed=30,xf=(512-2k,d),rdpct=0,seekpct=0

            rd=rd3,sd=sd1,iorate=10000,elapsed=30,xf=(4k-1m,d),rdpct=0,seekpct=0

            rd=rd4,sd=sd1,iorate=10000,elapsed=30,xf=(2m-16m,d),rdpct=0,seekpct=0,threads=32

            rd=rd5,sd=sd1,iorate=10000,elapsed=30,xf=(512-2k,d),rdpct=100,seekpct=0

            rd=rd6,sd=sd1,iorate=10000,elapsed=30,xf=(4k-1m,d),rdpct=100,seekpct=0

            rd=rd7,sd=sd1,iorate=10000,elapsed=30,xf=(2m-16m,d),rdpct=100,seekpct=0,threads=32

             

            2) I copy localhost-0.stdout.html here.

            For "linux_clock stderr: /root/nvme/vdbench503/linux/linux_clock.redhat: Permission denied."

              ==> When I run other cases, it also reports this, but other case can run through.

             

            ------------------------------------------------------------------------------------------------------------------------------------

            <pre>
            stdout/stderr for slave=localhost-0

            12:45:16.936 12:45:16.935 SlaveJvm execution parameter:  '-m localhost'
            12:45:16.936 12:45:16.935 SlaveJvm execution parameter:  '-n localhost-10-131011-12.45.16.025'
            12:45:16.936 12:45:16.935 SlaveJvm execution parameter:  '-l localhost-0'
            12:45:16.936 12:45:16.935 SlaveJvm execution parameter:  '-p 5570'
            12:45:16.936 12:45:16.936 SlaveJvm execution parameter:  '-d 25'
            12:45:16.936 12:45:16.936 SlaveJvm positional parameter: 'SlaveJvm'
            12:45:17.036 12:45:17.034 successfully connected to master localhost
            12:45:17.036 12:45:17.036 Connection to localhost using port 5570 successful
            12:45:17.450 12:45:17.450 execute(): /root/nvme/vdbench503/linux/linux_clock.suse
            12:45:17.478 12:45:17.477 Error running /root/nvme/vdbench503/linux/linux_clock.suse; trying redhat
            12:45:17.478 12:45:17.478 execute(): /root/nvme/vdbench503/linux/linux_clock.redhat
            12:45:17.495 12:45:17.495 linux_clock stderr: /root/nvme/vdbench503/linux/linux_clock.redhat: Permission denied.
            12:45:17.496 12:45:17.495
            12:45:17.496 12:45:17.495 Unexpected return values from 'linux_clock'; Linux processing disabled
            12:45:17.496 12:45:17.495
            12:45:17.499 12:45:17.499 /proc/stat:
            12:45:17.499 12:45:17.499 cpu  2236 596 997 3180085 9078 0 133 0 0 0
            12:45:17.499 12:45:17.499 cpu0 1499 3 624 794603 1539 0 8 0 0 0
            12:45:17.499 12:45:17.499 cpu1 275 205 126 794553 3106 0 18 0 0 0
            12:45:17.499 12:45:17.499 cpu2 194 266 104 796457 1168 0 91 0 0 0
            12:45:17.499 12:45:17.499 cpu3 266 121 142 794470 3264 0 14 0 0 0
            12:45:17.500 12:45:17.499 intr 32011333 119 2 0 3 3 0 1 0 0 0 0 0 4 0 1 1 176 0 0 0 0 0 0 30 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 28488 415 43473 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
            12:45:17.500 12:45:17.499 ctxt 3486302
            12:45:17.505 12:45:17.499 btime 1381458733
            12:45:17.505 12:45:17.502 processes 3657
            12:45:17.505 12:45:17.502 procs_running 2
            12:45:17.505 12:45:17.502 procs_blocked 0
            12:45:17.505 12:45:17.502 softirq 46110535 0 31936130 1323 45069 28579 0 10 13833010 0 266414
            12:45:17.515 12:45:17.514 Configuration interpretation took 0.07 seconds

            Link to Run Definitions:         <A HREF="#_1268799005">rd0 For loops: xfersize=4k rdpct=0.0 seekpct=100.0</A>
                                             <A HREF="#_192262325">rd2 For loops: xfersize=512.0 rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_1537491187">rd2 For loops: xfersize=1k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_2091139205">rd2 For loops: xfersize=2k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_59251633">rd3 For loops: xfersize=4k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_1557267270">rd3 For loops: xfersize=8k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_1607800901">rd3 For loops: xfersize=16k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_523012906">rd3 For loops: xfersize=32k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_627343971">rd3 For loops: xfersize=64k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_1772897474">rd3 For loops: xfersize=128k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_752243393">rd3 For loops: xfersize=256k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_718476262">rd3 For loops: xfersize=512k rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_129988353">rd3 For loops: xfersize=1m rdpct=0.0 seekpct=0.0</A>
                                             <A HREF="#_723379872">rd4 For loops: xfersize=2m rdpct=0.0 seekpct=0.0 threads=32.0</A>
                                             <A HREF="#_940583037">rd4 For loops: xfersize=4m rdpct=0.0 seekpct=0.0 threads=32.0</A>
                                             <A HREF="#_751977292">rd4 For loops: xfersize=8m rdpct=0.0 seekpct=0.0 threads=32.0</A>
                                             <A HREF="#_541084049">rd4 For loops: xfersize=16m rdpct=0.0 seekpct=0.0 threads=32.0</A>
                                             <A HREF="#_1553850145">rd5 For loops: xfersize=512.0 rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_10755848">rd5 For loops: xfersize=1k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_384910988">rd5 For loops: xfersize=2k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_978230552">rd6 For loops: xfersize=4k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_2133569679">rd6 For loops: xfersize=8k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_223657347">rd6 For loops: xfersize=16k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_912648779">rd6 For loops: xfersize=32k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_1559821779">rd6 For loops: xfersize=64k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_1591760724">rd6 For loops: xfersize=128k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_1518697589">rd6 For loops: xfersize=256k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_1907233728">rd6 For loops: xfersize=512k rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_1536351374">rd6 For loops: xfersize=1m rdpct=100.0 seekpct=0.0</A>
                                             <A HREF="#_114171290">rd7 For loops: xfersize=2m rdpct=100.0 seekpct=0.0 threads=32.0</A>
                                             <A HREF="#_1173974259">rd7 For loops: xfersize=4m rdpct=100.0 seekpct=0.0 threads=32.0</A>
                                             <A HREF="#_2053106024">rd7 For loops: xfersize=8m rdpct=100.0 seekpct=0.0 threads=32.0</A>
                                             <A HREF="#_785705372">rd7 For loops: xfersize=16m rdpct=100.0 seekpct=0.0 threads=32.0</A>

            12:45:17.831 12:45:17.831 Beginning of run setup
            12:45:17.831 12:45:17.831 **********************
            12:45:17.831
            12:45:17.832
            12:45:44.757 12:45:44.757 Allocating Data Validation map: 1572864000 one-byte entries for each 512-byte block.
            12:45:44.790 12:45:44.790 Opening sd=sd1,lun=/dev/nvme0n1; write: true; OpenFlags: 0x00004000 OtherFlags: 0x00000000
            12:45:44.851 12:45:44.851 Started 1 Workload Generator threads.
            12:45:44.851 12:45:44.851 work.use_waiter: false
            12:45:44.868 12:45:44.868 createCompressionPattern() seed: 0 comp_ratio:   1.00 limit:   0.00
            12:48:59.355 12:48:54.347 Started 256 i/o threads for sd1
            12:49:13.424 Killed

                                                                                                                          1,5           Top

            • 3. Re: Vdbench 503, ran into the following issu.
              Henk Vandenbergh-Oracle

              Some day I need to fix this, the fiddling with 'linux_clock. All I am trying to do is figure out how many clock ticks there are per second.

              Is the 'x' flag set on your file? (I have heard about some unzip utilities making a mess with file access bits).

               

              This does not appear to be your problem though. All I am seeing is '12:49:13.424 Killed', and that is not a message that Vdbench generates, it just reports it.