Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

test: running parallel tests. #569

Closed
DanielTimLee opened this issue Oct 21, 2018 · 11 comments · Fixed by #570
Closed

test: running parallel tests. #569

DanielTimLee opened this issue Oct 21, 2018 · 11 comments · Fixed by #570
Labels

Comments

@DanielTimLee
Copy link
Contributor

DanielTimLee commented Oct 21, 2018

Running all the test takes too long.
Shrinking test time using multi-workers might be needed.

Due to python multithread has GIL problem, implementing with multiprocess will be better.

If tests are executed concurrently, tests result won't be printed out in an orderly manner.
Collecting all the test results and when all the tests are done, print results with sort might be necessary.

Also during running concurrent tests, visualization is needed to inform users about the progress.

@DanielTimLee
Copy link
Contributor Author

DanielTimLee commented Oct 21, 2018

Execution Time Compare.

image

@DanielTimLee
Copy link
Contributor Author

DanielTimLee commented Oct 21, 2018

Demo of parallel test execution.
Execution of unittest is opt out in demo.

asciicast

@honggyukim
Copy link
Collaborator

Looks very cool! It may take some more time to review the code but it seems that my machine complains as follows:

$ make test
./unittest
        ...
unit test stats
====================
 40 ran successfully
  0 failed
  0 skipped
  0 signal caught
  0 unknown result

./runtest.py
Start 211 tests with 40 worker
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted211
Progress [########################################] 211/211
Test case                 pg             finstrument-fu
        ...

One more request is that it runs many tests in parallel, but it would be nice if it also has a way to stop testing with Ctrl-C. It currently cannot be stopped.

        ...
  File "/usr/lib/python2.7/multiprocessing/process.py", line 255, in _bootstrap                                                                               [1998/1998]
  File "/usr/lib/python2.7/multiprocessing/process.py", line 114, in run
KeyboardInterrupt
    task = get()
  File "/usr/lib/python2.7/multiprocessing/process.py", line 114, in run
    self.run()
    task = get()
    self.run()
    task = get()
  File "/usr/lib/python2.7/multiprocessing/process.py", line 114, in run
    self.run()
Traceback (most recent call last):
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python2.7/multiprocessing/process.py", line 114, in run
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python2.7/multiprocessing/process.py", line 258, in _bootstrap
  File "/usr/lib/python2.7/multiprocessing/process.py", line 114, in run
  File "/usr/lib/python2.7/multiprocessing/pool.py", line 102, in worker
    self._target(*self._args, **self._kwargs)
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python2.7/multiprocessing/pool.py", line 102, in worker
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python2.7/multiprocessing/pool.py", line 102, in worker
  File "/usr/lib/python2.7/multiprocessing/pool.py", line 102, in worker
  File "/usr/lib/python2.7/multiprocessing/pool.py", line 102, in worker
Traceback (most recent call last):
  File "/usr/lib/python2.7/multiprocessing/process.py", line 258, in _bootstrap
Traceback (most recent call last):
  File "/usr/lib/python2.7/multiprocessing/process.py", line 258, in _bootstrap
    racquire()
KeyboardInterrupt
  File "/usr/lib/python2.7/multiprocessing/process.py", line 258, in _bootstrap
    task = get()
    racquire()
    racquire()
    task = get()
    racquire()
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
    task = get()
    util._run_after_forkers()
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
KeyboardInterrupt
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
KeyboardInterrupt
  File "/usr/lib/python2.7/multiprocessing/util.py", line 157, in _run_after_forkers
KeyboardInterrupt
    task = get()
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
    task = get()
    task = get()
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
    task = get()
    self.run()
  File "/usr/lib/python2.7/multiprocessing/queues.py", line 376, in get
    self.run()
  File "/usr/lib/python2.7/multiprocessing/process.py", line 114, in run
  File "/usr/lib/python2.7/multiprocessing/process.py", line 114, in run
    task = get()
    self._target(*self._args, **self._kwargs)
    self._target(*self._args, **self._kwargs)
    racquire()
    racquire()
        ...

Thanks for this great work!

@DanielTimLee
Copy link
Contributor Author

Actually, if you are using python3 as runttest.py it stops with Ctrl+C, but python2 doesn't.
I'm not sure why is that, but still, have to look it further.

  • Could you let me know which env. you're working on when running mmap perf event test?
    cause looks you're running test 184, and on mine, I'm not encountering any of those errors.

Running environment

Manjaro Linux 18.0.0-rc (Arch Linux)
Python 2.7.15
Python 3.7.0

@honggyukim
Copy link
Collaborator

honggyukim commented Oct 22, 2018

Actually, if you are using python3 as runttest.py it stops with Ctrl+C, but python2 doesn't.
I'm not sure why is that, but still have to look it further.

Right. The execution cannot be stopped only when python2 is used. I tested it after explicitly changing to pyhon3, then it stops properly.

And "WARN: failed to mmap perf event: Operation not permitted" is printed when there are too many processes. I tested it with -j 8 but doesn't show the problem. (my machine has 40 logical cores)

Could you let me know which env. you're working on when running mmap perf event test?

I use Ubuntu 16.04 LTS(linux 4.4.0-116-generic) and python 2.7.12 and python 3.5.2.

It needs to be observed more later. Thanks.

@DanielTimLee
Copy link
Contributor Author

DanielTimLee commented Oct 23, 2018

Hmm. it's weird...
I've just tried on AWS m4.10xlarge (with 40 cores on it) ubuntu 16.04-server-20180126 (ami-ab77d4c5).

And I've got no such error like that.

Tested Environment

ubuntu@ip-172-31-14-87:~$ uname -a
Linux ip-172-31-14-87 4.4.0-1049-aws #58-Ubuntu SMP Fri Jan 12 23:17:09 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
ubuntu@ip-172-31-14-87:~$ cat /etc/lsb-release 
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=16.04
DISTRIB_CODENAME=xenial
DISTRIB_DESCRIPTION="Ubuntu 16.04.3 LTS"

build log attached.

ubuntu@ip-172-31-14-87:~/uftrace$ sudo apt-get install build-essential
...
ubuntu@ip-172-31-14-87:~/uftrace$ git remote add upstream https://github.com/DanielTimLee/uftrace
ubuntu@ip-172-31-14-87:~/uftrace$ git pull upstream
ubuntu@ip-172-31-14-87:~/uftrace$ git checkout test/parallel
ubuntu@ip-172-31-14-87:~/uftrace$ sudo ./misc/install-deps.sh 
ubuntu@ip-172-31-14-87:~/uftrace$ vim tests/runtest.py  # changed to python3
ubuntu@ip-172-31-14-87:~/uftrace$ make test            
./unittest 
...
./runtest.py 
Start 211 tests with 40 worker
Progress [########################################] 211/211
Test case                 pg             finstrument-fu
------------------------: O0 O1 O2 O3 Os O0 O1 O2 O3 Os
001 basic               : OK OK OK OK OK OK OK OK OK OK
002 argument            : OK OK OK OK OK OK OK OK OK OK
003 thread              : OK OK OK OK OK OK OK OK OK OK
004 filter_F            : OK OK OK OK OK OK OK OK OK OK
005 filter_N            : OK OK OK OK OK OK OK OK OK OK
006 filter_FN           : OK OK OK OK OK OK OK OK OK OK
007 library             : OK OK OK OK OK OK OK OK OK OK
008 daemon              : OK OK OK OK OK OK OK OK OK OK
009 fork                : OK OK OK OK OK OK OK OK OK OK
010 forkexec            : OK OK OK OK OK OK OK OK OK OK
011 vforkexec           : OK OK OK OK NG OK OK OK OK OK
012 demangle            : OK OK OK OK OK OK OK OK OK OK
013 signal              : OK OK OK OK OK OK OK OK OK OK
014 ucontext            : OK OK OK OK OK OK OK OK OK OK
015 longjmp             : OK OK OK OK OK OK OK OK OK OK
016 alloca              : OK OK OK OK OK OK OK OK OK OK
017 no_libcall          : OK OK OK OK OK OK OK OK OK OK
018 filter_regex        : OK OK OK OK OK OK OK OK OK OK
019 full_depth          : OK OK OK OK OK OK OK OK OK OK
020 filter_depth        : OK OK OK OK OK OK OK OK OK OK
021 filter_plt          : OK OK OK OK OK OK OK OK OK OK
022 filter_kernel       : SK SK SK SK SK SK SK SK SK SK
023 replay_filter       : OK OK OK OK OK OK OK OK OK OK
024 report_basic        : OK OK OK OK OK OK OK OK OK OK
025 report_s_call       : OK OK OK OK OK OK OK OK OK OK
026 filter_trigger      : OK OK OK OK OK OK OK OK OK OK
027 replay_filter_d     : OK OK OK OK OK OK OK OK OK OK
028 replay_backtrace    : OK OK OK OK OK OK OK OK OK OK
029 trigger_only        : OK OK OK OK OK OK OK OK OK OK
030 replay_trigger      : OK OK OK OK OK OK OK OK OK OK
031 filter_demangle1    : OK OK OK OK OK OK OK OK OK OK
032 filter_demangle2    : OK OK OK OK OK OK OK OK OK OK
033 filter_demangle3    : OK OK OK OK OK OK OK OK OK OK
034 filter_demangle4    : OK OK OK OK OK OK OK OK OK OK
035 filter_demangle5    : OK OK OK OK OK OK OK OK OK OK
036 replay_filter_N     : OK OK OK OK OK OK OK OK OK OK
037 trace_onoff         : OK OK OK OK OK OK OK OK OK OK
038 trace_disable       : OK OK OK OK OK OK OK OK OK OK
039 trace_onoff_F       : OK OK OK OK OK OK OK OK OK OK
040 replay_onoff        : OK OK OK OK OK OK OK OK OK OK
041 replay_onoff_N      : OK OK OK OK OK OK OK OK OK OK
042 live_disable        : OK OK OK OK OK OK OK OK OK OK
043 full_demangle       : NG NG NG NG NG NG NG NG NG NG
044 report_avg_total    : OK OK OK OK OK OK OK OK OK OK
045 report_avg_self     : OK OK OK OK OK OK OK OK OK OK
046 report_threads      : OK OK OK OK OK OK OK OK OK OK
047 signal2             : OK OK OK OK OK OK OK OK OK OK
048 malloc_impl         : OK OK OK OK OK OK OK OK OK OK
049 column_view         : OK OK OK OK OK OK OK OK OK OK
050 no_pltbind          : OK OK OK OK OK OK OK OK OK OK
051 return              : OK OK OK OK OK OK OK OK OK OK
052 nested_func         : OK OK OK OK OK NG NG NG NG NG
053 filter_time         : OK OK OK OK OK OK OK OK OK OK
054 filter_time_F       : OK OK OK OK OK OK OK OK OK OK
055 filter_time_N       : OK OK OK OK OK OK OK OK OK OK
056 filter_time_T       : OK OK OK OK OK OK OK OK OK OK
057 filter_time_D       : OK OK OK OK OK OK OK OK OK OK
058 arg_int             : OK OK OK OK OK SK SK SK SK SK
059 arg_str             : OK OK OK OK OK SK SK SK SK SK
060 arg_fmt             : OK OK OK OK OK SK SK SK SK SK
061 arg_plt             : OK OK OK OK OK OK OK OK OK OK
062 arg_char            : OK OK OK OK OK SK SK SK SK SK
063 retval              : OK OK OK OK OK SK SK SK SK SK
064 trigger_trace       : OK OK OK OK OK OK OK OK OK OK
065 arg_order           : OK OK OK OK OK SK SK SK SK SK
066 no_demangle         : OK OK OK OK OK OK OK OK OK OK
067 report_diff         : OK OK OK OK OK OK OK OK OK OK
068 filter_time_A       : OK OK OK OK OK SK SK SK SK SK
069 graph               : OK OK OK OK OK OK OK OK OK OK
070 graph_backtrace     : OK OK OK OK OK OK OK OK OK OK
071 graph_depth         : OK OK OK OK OK OK OK OK OK OK
072 no_comment          : OK OK OK OK OK OK OK OK OK OK
073 lib_filter          : OK OK OK OK OK OK OK OK OK OK
074 lib_trigger         : OK OK OK OK OK OK OK OK OK OK
075 lib_arg             : OK OK OK OK OK SK SK SK SK SK
076 lib_replay_F        : OK OK OK OK OK OK OK OK OK OK
077 lib_replay_T        : OK OK OK OK OK OK OK OK OK OK
078 max_stack           : OK OK OK OK OK OK OK OK OK OK
079 replay_kernel_D     : SK SK SK SK SK SK SK SK SK SK
080 replay_kernel_D2    : SK SK SK SK SK SK SK SK SK SK
081 kernel_depth        : SK SK SK SK SK SK SK SK SK SK
082 arg_many            : OK OK OK OK OK SK SK SK SK SK
083 arg_float           : OK OK OK OK OK SK SK SK SK SK
084 arg_mixed           : OK OK OK OK OK SK SK SK SK SK
085 arg_reg             : OK OK OK OK OK SK SK SK SK SK
086 arg_stack           : OK OK OK OK OK SK SK SK SK SK
087 arg_variadic        : OK OK OK OK OK SK SK SK SK SK
088 graph_session       : NG NG NG NG NG NG NG NG NG NG
089 graph_exit          : OK OK OK OK OK OK OK OK OK OK
090 report_recursive    : OK OK OK OK OK OK OK OK OK OK
091 replay_tid          : OK OK OK OK OK OK OK OK OK OK
092 report_tid          : OK OK OK OK OK OK OK OK OK OK
093 report_filter       : OK OK OK OK OK OK OK OK OK OK
094 report_depth        : OK OK OK OK OK OK OK OK OK OK
095 graph_tid           : OK OK OK OK OK OK OK OK OK OK
096 graph_filter        : OK OK OK OK OK OK OK OK OK OK
097 dump_basic          : OK OK OK OK OK OK OK OK OK OK
098 dump_tid            : OK OK OK OK OK OK OK OK OK OK
099 dump_filter         : OK OK OK OK OK OK OK OK OK OK
100 dump_depth          : OK OK OK OK OK OK OK OK OK OK
101 dump_chrome         : OK OK OK OK OK OK OK OK OK OK
102 dump_flamegraph     : OK OK OK OK OK OK OK OK OK OK
103 dump_kernel         : SK SK SK SK SK SK SK SK SK SK
104 graph_kernel        : SK SK SK SK SK SK SK SK SK SK
105 replay_time         : OK OK OK OK OK OK OK OK OK OK
106 report_time         : OK OK OK OK OK OK OK OK OK OK
107 dump_time           : OK OK OK OK OK OK OK OK OK OK
108 graph_time          : OK OK OK OK OK OK OK OK OK OK
109 replay_time_A       : OK OK OK OK OK SK SK SK SK SK
110 replay_time_T       : OK OK OK OK OK OK OK OK OK OK
111 kernel_tid          : SK SK SK SK SK SK SK SK SK SK
112 replay_skip         : OK OK OK OK OK OK OK OK OK OK
113 trigger_time        : OK OK OK OK OK OK OK OK OK OK
114 replay_trg_time     : OK OK OK OK OK OK OK OK OK OK
115 replay_field        : OK OK OK OK OK OK OK OK OK OK
116 field_none          : OK OK OK OK OK OK OK OK OK OK
117 time_range          : OK OK OK OK OK OK OK OK OK OK
118 thread_tsd          : OK OK OK OK OK OK OK OK OK OK
119 malloc_hook         : OK OK OK OK OK OK OK OK OK OK
120 malloc_tsd          : OK OK OK OK OK OK OK OK OK OK
121 malloc_fork         : OK OK OK OK OK OK OK OK OK OK
122 time_range2         : OK OK OK OK OK OK OK OK OK OK
123 backtrace           : OK OK OK OK OK OK OK OK OK OK
124 exception           : OK OK OK OK OK OK OK OK OK OK
125 report_range        : OK OK OK OK OK OK OK OK OK OK
126 arg_regex           : OK OK OK OK OK SK SK SK SK SK
127 arg_module          : OK OK OK OK OK SK SK SK SK SK
128 arg_module2         : OK OK OK OK OK SK SK SK SK SK
129 session_tid         : OK OK OK OK OK OK OK OK OK OK
130 thread_exec         : OK OK OK OK OK OK OK OK OK OK
131 lib_dlopen          : OK OK OK OK OK OK OK OK OK OK
132 trigger_kernel      : SK SK SK SK SK SK SK SK SK SK
133 long_string         : OK OK OK OK OK SK SK SK SK SK
134 pic_pie             : OK OK OK OK OK OK OK OK OK OK
135 trigger_time2       : OK OK OK OK OK OK OK OK OK OK
136 dynamic             : BI BI BI BI BI BI BI BI BI BI
137 kernel_tid_update   : SK SK SK SK SK SK SK SK SK SK
138 kernel_dynamic      : SK SK SK SK SK SK SK SK SK SK
139 kernel_dynamic2     : SK SK SK SK SK SK SK SK SK SK
140 dynamic_xray        : BI BI BI BI BI BI BI BI BI BI
141 recv_basic          : OK OK OK OK OK OK OK OK OK OK
142 recv_multi          : OK OK OK OK OK OK OK OK OK OK
143 recv_kernel         : SK SK SK SK SK SK SK SK SK SK
144 longjmp2            : OK OK OK OK OK OK OK OK OK OK
145 longjmp3            : OK OK OK OK OK OK OK OK OK OK
146 arg_std_string      : OK OK OK OK OK SK SK SK SK SK
147 event_sdt           : BI BI BI BI BI BI BI BI BI BI
148 event_kernel        : SK SK SK SK SK SK SK SK SK SK
149 event_kernel2       : SK SK SK SK SK SK SK SK SK SK
150 recv_event          : BI BI BI BI BI BI BI BI BI BI
151 recv_runcmd         : NG OK NG NG NG NG NG NG OK OK
152 read_proc_statm     : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
153 read_page_fault     : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
154 keep_pid            : OK OK OK OK OK OK OK OK OK OK
155 trigger_finish      : OK OK OK OK OK OK OK OK OK OK
156 trigger_finish2     : OK OK OK OK OK OK OK OK OK OK
157 script_python       : SK SK SK SK SK SK SK SK SK SK
158 report_diff_policy1 : OK OK OK OK OK OK OK OK OK OK
159 report_diff_policy2 : OK OK OK OK OK OK OK OK OK OK
160 report_diff_policy3 : OK OK OK OK OK OK OK OK OK OK
161 pltbind_now         : NG NG NG NG NG NG NG NG NG NG
162 pltbind_now_pie     : BI BI BI BI BI BI BI BI BI BI
163 event_sched         : SK SK SK SK SK SK SK SK SK SK
164 report_sched        : SK SK SK SK SK SK SK SK SK SK
165 graph_sched         : SK SK SK SK SK SK SK SK SK SK
166 dump_sched          : SK SK SK SK SK SK SK SK SK SK
167 recv_sched          : SK SK SK SK SK SK SK SK SK SK
168 lib_nested          : OK OK OK OK OK OK OK OK OK OK
169 script_args         : SK SK SK SK SK SK SK SK SK SK
170 script_filter       : SK SK SK SK SK SK SK SK SK SK
171 script_option       : SK SK SK SK SK SK SK SK SK SK
172 trigger_filter      : OK OK OK OK OK OK OK OK OK OK
173 trigger_args        : OK OK OK OK OK SK SK SK SK SK
174 replay_filter_kernel: SK SK SK SK SK SK SK SK SK SK
175 filter_time_read    : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
176 arg_fptr            : OK OK OK OK OK OK OK OK OK OK
177 report_diff_policy4 : OK OK OK OK OK OK OK OK OK OK
178 arg_auto1           : OK OK OK OK OK OK OK OK OK OK
179 arg_auto2           : OK OK OK OK OK OK OK OK OK OK
180 arg_auto3           : OK OK OK OK OK OK OK OK OK OK
181 graph_full          : NG NG NG NG NG NG NG NG NG NG
182 thread_exit         : SG OK OK OK OK SG OK OK OK OK
183 info_quote          : OK OK OK OK OK OK OK OK OK OK
184 arg_enum            : OK OK OK OK OK OK OK OK OK OK
185 exception2          : OK OK OK OK OK OK OK OK OK OK
186 exception3          : OK OK OK OK OK OK OK OK OK OK
187 graph_field         : OK OK OK OK OK OK OK OK OK OK
188 graph_field_none    : OK OK OK OK OK OK OK OK OK OK
189 replay_field2       : NG NG NG NG NG NG NG NG NG NG
190 trigger_autoargs    : OK OK OK OK OK OK OK OK OK OK
191 posix_spawn         : OK OK OK OK OK OK OK OK OK OK
192 lib_name            : OK OK OK OK OK OK OK OK OK OK
193 read_pmu_cycle      : NG NG NG NG NG NG NG NG NG NG
194 read_pmu_cache      : NG NG NG NG NG NG NG NG NG NG
195 read_pmu_branch     : NG NG NG NG NG NG NG NG NG NG
196 chrome_taskname     : NG NG NG NG NG NG NG NG NG NG
197 filter_glob         : OK OK OK OK OK OK OK OK OK OK
198 lib_arg_float       : OK OK OK OK OK SK SK SK SK SK
199 script_info         : SK SK SK SK SK SK SK SK SK SK
200 lib_dlopen2         : OK OK OK OK OK OK OK OK OK OK
201 arg_dwarf1          : NG NG NG NG NG SK SK SK SK SK
202 arg_dwarf2          : NG NG NG NG NG SK SK SK SK SK
203 arg_dwarf3          : NG NG NG NG NG SK SK SK SK SK
204 arg_dwarf4          : NG NG NG NG NG SK SK SK SK SK
205 arg_auto4           : NG NG NG NG NG SK SK SK SK SK
206 arg_enum2           : NG NG NG NG NG SK SK SK SK SK
207 dump_graphviz       : OK OK OK OK OK OK OK OK OK OK
208 watch_cpu           : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
209 filter_caller       : OK OK OK OK OK OK OK OK OK OK
210 filter_time_C       : OK OK OK OK OK OK OK OK OK OK
211 replay_filter_C     : OK OK OK OK OK OK OK OK OK OK

runtime test stats
====================
total  2110  Tests executed (success: 70.85%)
  OK:  1455  Test succeeded
  OK:    40  Test succeeded (with some fixup)
  NG:   133  Different test result
  NZ:    40  Non-zero return value
  SG:     2  Abnormal exit by signal
  TM:     0  Test ran too long
  BI:    50  Build failed
  LA:     0  Unsupported Language
  SK:   390  Skipped
ubuntu@ip-172-31-14-87:~/uftrace$ 

@namhyung
Copy link
Owner

@DanielTimLee your system may not provide perf event..

@DanielTimLee
Copy link
Contributor Author

DanielTimLee commented Oct 23, 2018

Oh. The warning is reproducible for me either.

ubuntu@ip-172-31-1-249:~/uftrace$ ls check-deps/perf_context_switch
check-deps/perf_context_switch

ubuntu@ip-172-31-1-249:~/uftrace$ export TESTARG='--sort -j 8'; make test
./runtest.py --sort -j 8
Progress [########################################] 211/211               
                                                                                                                                                                      
ubuntu@ip-172-31-1-249:~/uftrace$ export TESTARG='--sort -j 40'; make test
./runtest.py --sort -j 40
Start 211 tests with 40 worker
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted                                                                                                                                                                                        
WARN: failed to mmap perf event: Operation not permitted211                                                                                                                                                                                     
WARN: failed to mmap perf event: Operation not permitted211                                                                                                                                                                                     
Progress [########################################] 211/211                                                                                                                                                                                     

ubuntu@ip-172-31-1-249:~/uftrace$ cat /proc/sys/kernel/perf_event_paranoid
1
ubuntu@ip-172-31-1-249:~/uftrace$ sudo bash -c 'echo 2 > /proc/sys/kernel/perf_event_paranoid'

ubuntu@ip-172-31-1-249:~/uftrace$ export TESTARG='--sort -j 40'; make test
./runtest.py --sort -j 40
Start 211 tests with 40 worker
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted211
WARN: failed to mmap perf event: Operation not permitted                                                                                                                                                                                       
Progress [########################################] 211/211

namhyung added a commit that referenced this issue Nov 28, 2018
Parallel tests implementation with multiprocessing from Daniel.
It should speed up tests and improve the development.
Good job, Daniel!

Fixed: #569

Signed-off-by: Namhyung Kim <[email protected]>
@honggyukim
Copy link
Collaborator

Thanks very much for doing this work. But I still get many warning messages.

118 thread_tsd          : OK OK OK OK OK OK OK OK OK OK
119 malloc_hook         : OK OK OK OK OK OK OK OK OK OK
120 malloc_tsd          : OK OK OK OK OK OK OK OK OK OK
121 malloc_fork         : OK OK OK OK OK OK OK OK OK OK
122 time_range2         : OK OK OK OK OK OK OK OK OK OK
123 backtrace           : OK OK OK OK OK OK OK OK OK OK
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
124 exception           : OK OK OK OK OK OK OK OK OK OK
125 report_range        : OK OK OK OK OK OK OK OK OK OK
126 arg_regex           : OK OK OK OK OK SK SK SK SK SK
127 arg_module          : OK OK OK OK OK SK SK SK SK SK
128 arg_module2         : OK OK OK OK OK SK SK SK SK SK
129 session_tid         : OK OK OK OK OK OK OK OK OK OK
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
WARN: failed to mmap perf event: Operation not permitted
130 thread_exec         : OK OK OK OK OK OK OK OK OK OK
131 lib_dlopen          : OK OK OK OK OK OK OK OK OK OK
132 trigger_kernel      : SK SK SK SK SK SK SK SK SK SK

And some of the result results are randomly changed.

$ ./runtest.py
        ...
158 report_diff_policy1 : OK OK OK OK NG OK OK OK OK OK
159 report_diff_policy2 : OK OK OK OK OK OK OK OK OK OK
160 report_diff_policy3 : OK OK OK OK OK OK OK OK OK OK
161 pltbind_now         : NG NG NG NG NG NG NG NG NG NG
162 pltbind_now_pie     : BI BI BI BI BI BI BI BI BI BI
163 event_sched         : OK NG NG NG NG NG NG NG OK NG
164 report_sched        : OK OK NG NG NG NG NG OK OK OK
165 graph_sched         : OK NG OK OK OK OK NG NG NG OK
166 dump_sched          : OK OK OK OK OK OK OK OK OK OK
167 recv_sched          : OK NG OK OK OK NG OK OK OK OK
168 lib_nested          : OK OK OK OK OK OK OK OK OK OK
        ...

Many of 163 event_sched are failed but the result is different if I run it as a single test.

$ ./runtest.py 163
Start 1 tests with 40 worker
Test case                 pg             finstrument-fu
------------------------: O0 O1 O2 O3 Os O0 O1 O2 O3 Os
163 event_sched         : OK OK OK OK OK OK OK OK OK OK

The final result shows that many tests are failed anyway.

runtime test stats
====================
total  2120  Tests executed (success: 81.65%)
  OK:  1681  Test succeeded
  OK:    50  Test succeeded (with some fixup)
  NG:    72  Different test result
  NZ:     0  Non-zero return value
  SG:     2  Abnormal exit by signal
  TM:     0  Test ran too long
  BI:    20  Build failed
  LA:     0  Unsupported Language
  SK:   295  Skipped

We may have to fix some more sync issues.

@honggyukim honggyukim reopened this Nov 28, 2018
@namhyung
Copy link
Owner

Hmm.. looks like a problem regarding the perf event but it runs fine on my system. Anyway it's a different problem so I think we'd better discuss it on another issue. Could you please create one with the above info?

@honggyukim
Copy link
Collaborator

Okay. Please see #616. Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants