High cpu usage

[xvyvx]

• A brief description

The CPU usage is too high when running the following code on BashOnWindows:

#include <iostream>
#include <boost/asio.hpp>

boost::asio::io_service srv;

boost::asio::deadline_timer t(srv);

void Test(const boost::system::error_code &err)
{
    std::cout << "Test" << std::endl;
    t.expires_from_now(boost::posix_time::seconds(1));
    t.async_wait(Test);
}

int main()
{
    t.expires_from_now(boost::posix_time::seconds(1));
    t.async_wait(Test);
    srv.run();
    return 0;
}

• Expected results
  CPU usage should like below("top" output):
  
• Actual results
  CPU usage on BashOnWindows("top" output):
  
• Your Windows build number
  1607(14393.51)
• Steps / commands required to reproduce the error
  Using follow command to compile,and then run the test programme:

clang++ -std=c++11 -O3 -o test TestProgramme.cpp -I/mnt/d/boost_1_61_0/ -L/mnt/d/boost_1_61_0/stage/lib -lboost_system-mt

• Required packages and commands to install

Boost libraries 1.61(source code from offical site)
clang 3.8.1(Pre-Built Binaries from offical site)

[iz0eyj]

@xvyvx Check the real CPU usage, maybe wrong: #945

[xvyvx]

@iz0eyj By re-running the test program,windows task manager displayed as follow:

[aseering]

This might be related to #616 (a hang when using boost::asio). Probably not the same cause, but something that library does seems to make WSL act up.

[xilun]

I've been able to repro it with the boost packaged in Ubuntu 14.04, and a binary built with gcc:

sudo apt-get install libboost-dev libboost-system-dev
g++ -O2 -DBOOST_SYSTEM_NO_DEPRECATED -o test.bin test.cpp  -lboost_system

Excerpt of strace:

23:03:05.761746 eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 3
23:03:05.777235 epoll_create1(EPOLL_CLOEXEC) = 4
23:03:05.777235 timerfd_create(CLOCK_MONOTONIC, 0x80000 /* TFD_??? */) = 5
23:03:05.777235 epoll_ctl(4, EPOLL_CTL_ADD, 3, {EPOLLIN|EPOLLERR|EPOLLET, {u32=26116584, u64=26116584}}) = 0
23:03:05.777235 write(3, "\1\0\0\0\0\0\0\0", 8) = 8
23:03:05.777235 epoll_ctl(4, EPOLL_CTL_ADD, 5, {EPOLLIN|EPOLLERR, {u32=26116596, u64=26116596}}) = 0
23:03:05.777235 gettimeofday({1472072585, 777235}, NULL) = 0
23:03:05.777235 open("/etc/localtime", O_RDONLY|O_CLOEXEC) = 6
23:03:05.777235 fstat(6, {st_mode=S_IFREG|0644, st_size=1073, ...}) = 0
23:03:05.777235 fstat(6, {st_mode=S_IFREG|0644, st_size=1073, ...}) = 0
23:03:05.777235 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0918c60000
23:03:05.777235 read(6, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\2\0\0\0\2\0\0\0\0"..., 512) = 512
23:03:05.777235 lseek(6, -124, SEEK_CUR) = 388
23:03:05.777235 read(6, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\2\0\0\0\2\0\0\0\0"..., 512) = 512
23:03:05.792996 read(6, "z\260\246\20\0\0\0\0{\316\273\220\0\0\0\0|\231\302\220\0\0\0\0}\256\235\220\0\0\0\0"..., 512) = 173
23:03:05.792996 close(6)                = 0
23:03:05.792996 munmap(0x7f0918c60000, 4096) = 0
23:03:05.792996 gettimeofday({1472072585, 792996}, NULL) = 0
23:03:05.792996 timerfd_settime(5, 0, {it_interval={0, 0}, it_value={0, 984239000}}, {it_interval={212338875786777235, 6354328}, it_value={0, 139677033506496}}) = 0
23:03:05.792996 epoll_wait(4, {{EPOLLIN, {u32=26116584, u64=26116584}}}, 128, -1) = 1
23:03:05.792996 epoll_wait(4, {{EPOLLIN, {u32=26116596, u64=26116596}}}, 128, -1) = 1
23:03:06.786729 gettimeofday({1472072586, 786729}, NULL) = 0
23:03:06.786729 timerfd_settime(5, 0, {it_interval={0, 0}, it_value={300, 0}}, {it_interval={2463081968084975653, 2469415157354594432}, it_value={9946315639708712962, 2304}}) = 0
23:03:06.786729 fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(4, 2), ...}) = 0
23:03:06.786729 ioctl(1, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
23:03:06.786729 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0918c60000
23:03:06.786729 write(1, "Test\n", 5Test
)   = 5
23:03:06.786729 gettimeofday({1472072586, 786729}, NULL) = 0
23:03:06.786729 gettimeofday({1472072586, 786729}, NULL) = 0
23:03:06.786729 timerfd_settime(5, 0, {it_interval={0, 0}, it_value={1, 0}}, {it_interval={212338875787786729, 6354328}, it_value={0, 0}}) = 0
23:03:06.786729 epoll_wait(4, {{EPOLLIN, {u32=26116596, u64=26116596}}}, 128, -1) = 1
23:03:06.786729 gettimeofday({1472072586, 786729}, NULL) = 0
23:03:06.786729 gettimeofday({1472072586, 786729}, NULL) = 0
23:03:06.786729 timerfd_settime(5, 0, {it_interval={0, 0}, it_value={1, 0}}, {it_interval={0, 0}, it_value={0, 0}}) = 0
23:03:06.786729 epoll_wait(4, {{EPOLLIN, {u32=26116596, u64=26116596}}}, 128, -1) = 1
23:03:06.786729 gettimeofday({1472072586, 802405}, NULL) = 0
23:03:06.802405 gettimeofday({1472072586, 802405}, NULL) = 0
23:03:06.802405 timerfd_settime(5, 0, {it_interval={0, 0}, it_value={0, 984324000}}, {it_interval={0, 0}, it_value={0, 996372000}}) = 0
23:03:06.802405 epoll_wait(4, {{EPOLLIN, {u32=26116596, u64=26116596}}}, 128, -1) = 1
23:03:06.802405 gettimeofday({1472072586, 802405}, NULL) = 0
23:03:06.802405 gettimeofday({1472072586, 802405}, NULL) = 0
23:03:06.802405 timerfd_settime(5, 0, {it_interval={0, 0}, it_value={0, 984324000}}, {it_interval={0, 0}, it_value={0, 991152000}}) = 0
23:03:06.802405 epoll_wait(4, {{EPOLLIN, {u32=26116596, u64=26116596}}}, 128, -1) = 1
23:03:06.802405 gettimeofday({1472072586, 802405}, NULL) = 0
23:03:06.802405 gettimeofday({1472072586, 802405}, NULL) = 0

[stehufntdev]

Thanks for reporting the issue, a fix for this should be out for insider builds soon.

[jlevitt]

Is this fix available? If so how do I get it?

[therealkenc]

This was marked fixinbound 6th of January 2017, referenced in 15019. So Creator Update 15063. If the repro in the OP still manifests (I haven't checked), it should get a new issue since this one sailed.