* [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? @ 2017-06-16 8:11 Sam 2017-06-16 8:26 ` Sam 2017-06-19 9:30 ` [Qemu-devel] Fwd: " Sam 0 siblings, 2 replies; 8+ messages in thread From: Sam @ 2017-06-16 8:11 UTC (permalink / raw) To: dev, users Hi all, I'm running `QEMU_CMD ...` to create a vm under dpdk huge page envriment (which set huge page 1G). And I enable all events in qemu. For qemu and ovs-dpdk(ovs-2.4.9 with dpdk-2.2.0) environment, detail log is: > 30012@1497443246.678304:object_dynamic_cast_assert qemu:memory-region->qemu:memory-region (/home/hu > anghuai/cloud/contrib/qemu-2.6.0/memory.c:1076:memory_region_initfn) > 30012@1497443256.274866:object_dynamic_cast_assert qio-channel-socket->qio-channel-socket (io/chann > el-socket.c:389:qio_channel_socket_init) I don't know why qemu doing 'memory_region_initfn' function in this 10 second, does anyone know this? static void memory_region_initfn(Object *obj) > { > MemoryRegion *mr = MEMORY_REGION(obj); > ObjectProperty *op; > mr->ops = &unassigned_mem_ops; > mr->enabled = true; > mr->romd_mode = true; > mr->global_locking = true; > mr->destructor = memory_region_destructor_none; > QTAILQ_INIT(&mr->subregions); > QTAILQ_INIT(&mr->coalesced); > op = object_property_add(OBJECT(mr), "container", > "link<" TYPE_MEMORY_REGION ">", > memory_region_get_container, > NULL, /* memory_region_set_container */ > NULL, NULL, &error_abort); > op->resolve = memory_region_resolve_container; > object_property_add(OBJECT(mr), "addr", "uint64", > memory_region_get_addr, > NULL, /* memory_region_set_addr */ > NULL, NULL, &error_abort); > object_property_add(OBJECT(mr), "priority", "uint32", > memory_region_get_priority, > NULL, /* memory_region_set_priority */ > NULL, NULL, &error_abort); > object_property_add_bool(OBJECT(mr), "may-overlap", > memory_region_get_may_overlap, > NULL, /* memory_region_set_may_overlap */ > &error_abort); > object_property_add(OBJECT(mr), "size", "uint64", > memory_region_get_size, > NULL, /* memory_region_set_size, */ > NULL, NULL, &error_abort); > } Thank you~ ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? 2017-06-16 8:11 [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? Sam @ 2017-06-16 8:26 ` Sam 2017-06-16 8:59 ` Bruce Richardson 2017-06-19 9:30 ` [Qemu-devel] Fwd: " Sam 1 sibling, 1 reply; 8+ messages in thread From: Sam @ 2017-06-16 8:26 UTC (permalink / raw) To: dev, users BTW, while running ovs-dpdk, this log is also take long time, does that mean dpdk request large memory take long time? EAL: Setting up physically contiguous memory... 2017-06-16 16:11 GMT+08:00 Sam <batmanustc@gmail.com>: > Hi all, > > I'm running `QEMU_CMD ...` to create a vm under dpdk huge page envriment > (which set huge page 1G). And I enable all events in qemu. > > For qemu and ovs-dpdk(ovs-2.4.9 with dpdk-2.2.0) environment, detail log > is: > > > 30012@1497443246.678304:object_dynamic_cast_assert > qemu:memory-region->qemu:memory-region (/home/hu > > anghuai/cloud/contrib/qemu-2.6.0/memory.c:1076:memory_region_initfn) > > 30012@1497443256.274866:object_dynamic_cast_assert > qio-channel-socket->qio-channel-socket (io/chann > > el-socket.c:389:qio_channel_socket_init) > > > I don't know why qemu doing 'memory_region_initfn' function in this 10 > second, does anyone know this? > > static void memory_region_initfn(Object *obj) >> { >> MemoryRegion *mr = MEMORY_REGION(obj); >> ObjectProperty *op; >> mr->ops = &unassigned_mem_ops; >> mr->enabled = true; >> mr->romd_mode = true; >> mr->global_locking = true; >> mr->destructor = memory_region_destructor_none; >> QTAILQ_INIT(&mr->subregions); >> QTAILQ_INIT(&mr->coalesced); >> op = object_property_add(OBJECT(mr), "container", >> "link<" TYPE_MEMORY_REGION ">", >> memory_region_get_container, >> NULL, /* memory_region_set_container */ >> NULL, NULL, &error_abort); >> op->resolve = memory_region_resolve_container; >> object_property_add(OBJECT(mr), "addr", "uint64", >> memory_region_get_addr, >> NULL, /* memory_region_set_addr */ >> NULL, NULL, &error_abort); >> object_property_add(OBJECT(mr), "priority", "uint32", >> memory_region_get_priority, >> NULL, /* memory_region_set_priority */ >> NULL, NULL, &error_abort); >> object_property_add_bool(OBJECT(mr), "may-overlap", >> memory_region_get_may_overlap, >> NULL, /* memory_region_set_may_overlap */ >> &error_abort); >> object_property_add(OBJECT(mr), "size", "uint64", >> memory_region_get_size, >> NULL, /* memory_region_set_size, */ >> NULL, NULL, &error_abort); >> } > > > Thank you~ > ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? 2017-06-16 8:26 ` Sam @ 2017-06-16 8:59 ` Bruce Richardson 2017-06-19 3:12 ` Sam 0 siblings, 1 reply; 8+ messages in thread From: Bruce Richardson @ 2017-06-16 8:59 UTC (permalink / raw) To: Sam; +Cc: dev, users On Fri, Jun 16, 2017 at 04:26:40PM +0800, Sam wrote: > BTW, while running ovs-dpdk, this log is also take long time, does that > mean dpdk request large memory take long time? > > EAL: Setting up physically contiguous memory... > When running with 1G pages, I found that the mmap system call takes a considerable amount of time to execute. I think this is due to the kernel zero-ing out the 1G pages. IIRC on one system I measured it as taking about 0.4 seconds per 1G page. /Bruce > > 2017-06-16 16:11 GMT+08:00 Sam <batmanustc@gmail.com>: > > > Hi all, > > > > I'm running `QEMU_CMD ...` to create a vm under dpdk huge page envriment > > (which set huge page 1G). And I enable all events in qemu. > > > > For qemu and ovs-dpdk(ovs-2.4.9 with dpdk-2.2.0) environment, detail log > > is: > > > > > 30012@1497443246.678304:object_dynamic_cast_assert > > qemu:memory-region->qemu:memory-region (/home/hu > > > anghuai/cloud/contrib/qemu-2.6.0/memory.c:1076:memory_region_initfn) > > > 30012@1497443256.274866:object_dynamic_cast_assert > > qio-channel-socket->qio-channel-socket (io/chann > > > el-socket.c:389:qio_channel_socket_init) > > > > > > I don't know why qemu doing 'memory_region_initfn' function in this 10 > > second, does anyone know this? > > > > static void memory_region_initfn(Object *obj) > >> { > >> MemoryRegion *mr = MEMORY_REGION(obj); > >> ObjectProperty *op; > >> mr->ops = &unassigned_mem_ops; > >> mr->enabled = true; > >> mr->romd_mode = true; > >> mr->global_locking = true; > >> mr->destructor = memory_region_destructor_none; > >> QTAILQ_INIT(&mr->subregions); > >> QTAILQ_INIT(&mr->coalesced); > >> op = object_property_add(OBJECT(mr), "container", > >> "link<" TYPE_MEMORY_REGION ">", > >> memory_region_get_container, > >> NULL, /* memory_region_set_container */ > >> NULL, NULL, &error_abort); > >> op->resolve = memory_region_resolve_container; > >> object_property_add(OBJECT(mr), "addr", "uint64", > >> memory_region_get_addr, > >> NULL, /* memory_region_set_addr */ > >> NULL, NULL, &error_abort); > >> object_property_add(OBJECT(mr), "priority", "uint32", > >> memory_region_get_priority, > >> NULL, /* memory_region_set_priority */ > >> NULL, NULL, &error_abort); > >> object_property_add_bool(OBJECT(mr), "may-overlap", > >> memory_region_get_may_overlap, > >> NULL, /* memory_region_set_may_overlap */ > >> &error_abort); > >> object_property_add(OBJECT(mr), "size", "uint64", > >> memory_region_get_size, > >> NULL, /* memory_region_set_size, */ > >> NULL, NULL, &error_abort); > >> } > > > > > > Thank you~ > > ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? 2017-06-16 8:59 ` Bruce Richardson @ 2017-06-19 3:12 ` Sam 2017-06-19 3:13 ` Sam 0 siblings, 1 reply; 8+ messages in thread From: Sam @ 2017-06-19 3:12 UTC (permalink / raw) To: Bruce Richardson; +Cc: dev, users Hi, I print all system call by `strace -f -T -tt -e trace=all -o output.txt $QEMU_CMD`, and I found this: 5900 11:08:11.288701 nanosleep({0, 10000000}, 0x7ff103c13a80) = 0 > <0.010171> > 5900 11:08:11.299052 futex(0x7ff10be24340, FUTEX_WAIT_PRIVATE, 2, NULL > <unfinished ...> > 5899 11:08:20.138492 rt_sigaction(SIGBUS, {0x7ff10b5b1040, [], > SA_RESTORER|SA_SIGINFO, 0x7ff1085fd100}, NULL, 8) = 0 <0.000012> > 5899 11:08:20.138598 rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], > NULL, 8) = 0 <0.000008> > 5899 11:08:20.138646 mmap(NULL, 266240, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b380000 <0.000013> > 5899 11:08:20.138793 mmap(NULL, 266240, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b33f000 <0.000009> I don't know who call `futex`, and why waste such long time. And for `mmap` system call, I don't found this system call waste too much time. WHY.... 2017-06-16 16:59 GMT+08:00 Bruce Richardson <bruce.richardson@intel.com>: > On Fri, Jun 16, 2017 at 04:26:40PM +0800, Sam wrote: > > BTW, while running ovs-dpdk, this log is also take long time, does that > > mean dpdk request large memory take long time? > > > > EAL: Setting up physically contiguous memory... > > > > When running with 1G pages, I found that the mmap system call takes a > considerable amount of time to execute. I think this is due to the > kernel zero-ing out the 1G pages. IIRC on one system I measured it as > taking > about 0.4 seconds per 1G page. > > /Bruce > > > > > 2017-06-16 16:11 GMT+08:00 Sam <batmanustc@gmail.com>: > > > > > Hi all, > > > > > > I'm running `QEMU_CMD ...` to create a vm under dpdk huge page > envriment > > > (which set huge page 1G). And I enable all events in qemu. > > > > > > For qemu and ovs-dpdk(ovs-2.4.9 with dpdk-2.2.0) environment, detail > log > > > is: > > > > > > > 30012@1497443246.678304:object_dynamic_cast_assert > > > qemu:memory-region->qemu:memory-region (/home/hu > > > > anghuai/cloud/contrib/qemu-2.6.0/memory.c:1076:memory_region_initfn) > > > > 30012@1497443256.274866:object_dynamic_cast_assert > > > qio-channel-socket->qio-channel-socket (io/chann > > > > el-socket.c:389:qio_channel_socket_init) > > > > > > > > > I don't know why qemu doing 'memory_region_initfn' function in this 10 > > > second, does anyone know this? > > > > > > static void memory_region_initfn(Object *obj) > > >> { > > >> MemoryRegion *mr = MEMORY_REGION(obj); > > >> ObjectProperty *op; > > >> mr->ops = &unassigned_mem_ops; > > >> mr->enabled = true; > > >> mr->romd_mode = true; > > >> mr->global_locking = true; > > >> mr->destructor = memory_region_destructor_none; > > >> QTAILQ_INIT(&mr->subregions); > > >> QTAILQ_INIT(&mr->coalesced); > > >> op = object_property_add(OBJECT(mr), "container", > > >> "link<" TYPE_MEMORY_REGION ">", > > >> memory_region_get_container, > > >> NULL, /* memory_region_set_container */ > > >> NULL, NULL, &error_abort); > > >> op->resolve = memory_region_resolve_container; > > >> object_property_add(OBJECT(mr), "addr", "uint64", > > >> memory_region_get_addr, > > >> NULL, /* memory_region_set_addr */ > > >> NULL, NULL, &error_abort); > > >> object_property_add(OBJECT(mr), "priority", "uint32", > > >> memory_region_get_priority, > > >> NULL, /* memory_region_set_priority */ > > >> NULL, NULL, &error_abort); > > >> object_property_add_bool(OBJECT(mr), "may-overlap", > > >> memory_region_get_may_overlap, > > >> NULL, /* memory_region_set_may_overlap */ > > >> &error_abort); > > >> object_property_add(OBJECT(mr), "size", "uint64", > > >> memory_region_get_size, > > >> NULL, /* memory_region_set_size, */ > > >> NULL, NULL, &error_abort); > > >> } > > > > > > > > > Thank you~ > > > > ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? 2017-06-19 3:12 ` Sam @ 2017-06-19 3:13 ` Sam 0 siblings, 0 replies; 8+ messages in thread From: Sam @ 2017-06-19 3:13 UTC (permalink / raw) To: Bruce Richardson; +Cc: dev, users Additional, this is DPDK-QEMU enviroment. 2017-06-19 11:12 GMT+08:00 Sam <batmanustc@gmail.com>: > Hi, > > I print all system call by `strace -f -T -tt -e trace=all -o output.txt > $QEMU_CMD`, and I found this: > > 5900 11:08:11.288701 nanosleep({0, 10000000}, 0x7ff103c13a80) = 0 >> <0.010171> >> 5900 11:08:11.299052 futex(0x7ff10be24340, FUTEX_WAIT_PRIVATE, 2, NULL >> <unfinished ...> >> 5899 11:08:20.138492 rt_sigaction(SIGBUS, {0x7ff10b5b1040, [], >> SA_RESTORER|SA_SIGINFO, 0x7ff1085fd100}, NULL, 8) = 0 <0.000012> >> 5899 11:08:20.138598 rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], >> NULL, 8) = 0 <0.000008> >> 5899 11:08:20.138646 mmap(NULL, 266240, PROT_READ|PROT_WRITE, >> MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b380000 <0.000013> >> 5899 11:08:20.138793 mmap(NULL, 266240, PROT_READ|PROT_WRITE, >> MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b33f000 <0.000009> > > > I don't know who call `futex`, and why waste such long time. And for > `mmap` system call, I don't found this system call waste too much time. > > WHY.... > > > 2017-06-16 16:59 GMT+08:00 Bruce Richardson <bruce.richardson@intel.com>: > >> On Fri, Jun 16, 2017 at 04:26:40PM +0800, Sam wrote: >> > BTW, while running ovs-dpdk, this log is also take long time, does that >> > mean dpdk request large memory take long time? >> > >> > EAL: Setting up physically contiguous memory... >> > >> >> When running with 1G pages, I found that the mmap system call takes a >> considerable amount of time to execute. I think this is due to the >> kernel zero-ing out the 1G pages. IIRC on one system I measured it as >> taking >> about 0.4 seconds per 1G page. >> >> /Bruce >> >> > >> > 2017-06-16 16:11 GMT+08:00 Sam <batmanustc@gmail.com>: >> > >> > > Hi all, >> > > >> > > I'm running `QEMU_CMD ...` to create a vm under dpdk huge page >> envriment >> > > (which set huge page 1G). And I enable all events in qemu. >> > > >> > > For qemu and ovs-dpdk(ovs-2.4.9 with dpdk-2.2.0) environment, detail >> log >> > > is: >> > > >> > > > 30012@1497443246.678304:object_dynamic_cast_assert >> > > qemu:memory-region->qemu:memory-region (/home/hu >> > > > anghuai/cloud/contrib/qemu-2.6.0/memory.c:1076:memory_region >> _initfn) >> > > > 30012@1497443256.274866:object_dynamic_cast_assert >> > > qio-channel-socket->qio-channel-socket (io/chann >> > > > el-socket.c:389:qio_channel_socket_init) >> > > >> > > >> > > I don't know why qemu doing 'memory_region_initfn' function in this 10 >> > > second, does anyone know this? >> > > >> > > static void memory_region_initfn(Object *obj) >> > >> { >> > >> MemoryRegion *mr = MEMORY_REGION(obj); >> > >> ObjectProperty *op; >> > >> mr->ops = &unassigned_mem_ops; >> > >> mr->enabled = true; >> > >> mr->romd_mode = true; >> > >> mr->global_locking = true; >> > >> mr->destructor = memory_region_destructor_none; >> > >> QTAILQ_INIT(&mr->subregions); >> > >> QTAILQ_INIT(&mr->coalesced); >> > >> op = object_property_add(OBJECT(mr), "container", >> > >> "link<" TYPE_MEMORY_REGION ">", >> > >> memory_region_get_container, >> > >> NULL, /* memory_region_set_container */ >> > >> NULL, NULL, &error_abort); >> > >> op->resolve = memory_region_resolve_container; >> > >> object_property_add(OBJECT(mr), "addr", "uint64", >> > >> memory_region_get_addr, >> > >> NULL, /* memory_region_set_addr */ >> > >> NULL, NULL, &error_abort); >> > >> object_property_add(OBJECT(mr), "priority", "uint32", >> > >> memory_region_get_priority, >> > >> NULL, /* memory_region_set_priority */ >> > >> NULL, NULL, &error_abort); >> > >> object_property_add_bool(OBJECT(mr), "may-overlap", >> > >> memory_region_get_may_overlap, >> > >> NULL, /* memory_region_set_may_overlap >> */ >> > >> &error_abort); >> > >> object_property_add(OBJECT(mr), "size", "uint64", >> > >> memory_region_get_size, >> > >> NULL, /* memory_region_set_size, */ >> > >> NULL, NULL, &error_abort); >> > >> } >> > > >> > > >> > > Thank you~ >> > > >> > > ^ permalink raw reply [flat|nested] 8+ messages in thread
* [Qemu-devel] Fwd: [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? 2017-06-16 8:11 [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? Sam 2017-06-16 8:26 ` Sam @ 2017-06-19 9:30 ` Sam 2017-06-19 9:45 ` Daniel P. Berrange 1 sibling, 1 reply; 8+ messages in thread From: Sam @ 2017-06-19 9:30 UTC (permalink / raw) To: qemu-devel, qemu-discuss Hi all, I'm running `QEMU_CMD ...` to create a vm under dpdk huge page envriment (which set huge page 1G). And I enable all events in qemu. For qemu and ovs-dpdk(ovs-2.4.9 with dpdk-2.2.0) environment, detail log is: > 30012@1497443246.678304:object_dynamic_cast_assert qemu:memory-region->qemu:memory-region (/home/hu > anghuai/cloud/contrib/qemu-2.6.0/memory.c:1076:memory_region_initfn) > 30012@1497443256.274866:object_dynamic_cast_assert qio-channel-socket->qio-channel-socket (io/chann > el-socket.c:389:qio_channel_socket_init) I don't know why qemu doing 'memory_region_initfn' function in this 10 second, does anyone know this? static void memory_region_initfn(Object *obj) > { > MemoryRegion *mr = MEMORY_REGION(obj); > ObjectProperty *op; > mr->ops = &unassigned_mem_ops; > mr->enabled = true; > mr->romd_mode = true; > mr->global_locking = true; > mr->destructor = memory_region_destructor_none; > QTAILQ_INIT(&mr->subregions); > QTAILQ_INIT(&mr->coalesced); > op = object_property_add(OBJECT(mr), "container", > "link<" TYPE_MEMORY_REGION ">", > memory_region_get_container, > NULL, /* memory_region_set_container */ > NULL, NULL, &error_abort); > op->resolve = memory_region_resolve_container; > object_property_add(OBJECT(mr), "addr", "uint64", > memory_region_get_addr, > NULL, /* memory_region_set_addr */ > NULL, NULL, &error_abort); > object_property_add(OBJECT(mr), "priority", "uint32", > memory_region_get_priority, > NULL, /* memory_region_set_priority */ > NULL, NULL, &error_abort); > object_property_add_bool(OBJECT(mr), "may-overlap", > memory_region_get_may_overlap, > NULL, /* memory_region_set_may_overlap */ > &error_abort); > object_property_add(OBJECT(mr), "size", "uint64", > memory_region_get_size, > NULL, /* memory_region_set_size, */ > NULL, NULL, &error_abort); > } I print all system call by `strace -f -T -tt -e trace=all -o output.txt $QEMU_CMD`, and I found this: 5900 11:08:11.288701 nanosleep({0, 10000000}, 0x7ff103c13a80) = 0 > <0.010171> > 5900 11:08:11.299052 futex(0x7ff10be24340, FUTEX_WAIT_PRIVATE, 2, NULL > <unfinished ...> > 5899 11:08:20.138492 rt_sigaction(SIGBUS, {0x7ff10b5b1040, [], > SA_RESTORER|SA_SIGINFO, 0x7ff1085fd100}, NULL, 8) = 0 <0.000012> > 5899 11:08:20.138598 rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], > NULL, 8) = 0 <0.000008> > 5899 11:08:20.138646 mmap(NULL, 266240, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b380000 <0.000013> > 5899 11:08:20.138793 mmap(NULL, 266240, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b33f000 <0.000009> I don't know who call `futex`, and why waste such long time. Thank you~ ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Qemu-devel] Fwd: [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? 2017-06-19 9:30 ` [Qemu-devel] Fwd: " Sam @ 2017-06-19 9:45 ` Daniel P. Berrange 2017-06-20 2:23 ` Sam 0 siblings, 1 reply; 8+ messages in thread From: Daniel P. Berrange @ 2017-06-19 9:45 UTC (permalink / raw) To: Sam; +Cc: qemu-devel, qemu-discuss On Mon, Jun 19, 2017 at 05:30:59PM +0800, Sam wrote: > Hi all, > > I'm running `QEMU_CMD ...` to create a vm under dpdk huge page envriment > (which set huge page 1G). And I enable all events in qemu. Please provide the full QEMU command line you are using. > For qemu and ovs-dpdk(ovs-2.4.9 with dpdk-2.2.0) environment, detail log is: > > > 30012@1497443246.678304:object_dynamic_cast_assert > qemu:memory-region->qemu:memory-region (/home/hu > > anghuai/cloud/contrib/qemu-2.6.0/memory.c:1076:memory_region_initfn) > > 30012@1497443256.274866:object_dynamic_cast_assert > qio-channel-socket->qio-channel-socket (io/chann > > el-socket.c:389:qio_channel_socket_init) > > > I don't know why qemu doing 'memory_region_initfn' function in this 10 > second, does anyone know this? If memory initialization takes a long time, this is likely a result of QEMU pre-allocating the memory pages, which is a fairly slow procedure, that can have noticable startup time impact for guests with large RAM > static void memory_region_initfn(Object *obj) > > { > > MemoryRegion *mr = MEMORY_REGION(obj); > > ObjectProperty *op; > > mr->ops = &unassigned_mem_ops; > > mr->enabled = true; > > mr->romd_mode = true; > > mr->global_locking = true; > > mr->destructor = memory_region_destructor_none; > > QTAILQ_INIT(&mr->subregions); > > QTAILQ_INIT(&mr->coalesced); > > op = object_property_add(OBJECT(mr), "container", > > "link<" TYPE_MEMORY_REGION ">", > > memory_region_get_container, > > NULL, /* memory_region_set_container */ > > NULL, NULL, &error_abort); > > op->resolve = memory_region_resolve_container; > > object_property_add(OBJECT(mr), "addr", "uint64", > > memory_region_get_addr, > > NULL, /* memory_region_set_addr */ > > NULL, NULL, &error_abort); > > object_property_add(OBJECT(mr), "priority", "uint32", > > memory_region_get_priority, > > NULL, /* memory_region_set_priority */ > > NULL, NULL, &error_abort); > > object_property_add_bool(OBJECT(mr), "may-overlap", > > memory_region_get_may_overlap, > > NULL, /* memory_region_set_may_overlap */ > > &error_abort); > > object_property_add(OBJECT(mr), "size", "uint64", > > memory_region_get_size, > > NULL, /* memory_region_set_size, */ > > NULL, NULL, &error_abort); > > } > > > I print all system call by `strace -f -T -tt -e trace=all -o output.txt > $QEMU_CMD`, and I found this: > > 5900 11:08:11.288701 nanosleep({0, 10000000}, 0x7ff103c13a80) = 0 > > <0.010171> > > 5900 11:08:11.299052 futex(0x7ff10be24340, FUTEX_WAIT_PRIVATE, 2, NULL > > <unfinished ...> > > 5899 11:08:20.138492 rt_sigaction(SIGBUS, {0x7ff10b5b1040, [], > > SA_RESTORER|SA_SIGINFO, 0x7ff1085fd100}, NULL, 8) = 0 <0.000012> > > 5899 11:08:20.138598 rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], > > NULL, 8) = 0 <0.000008> > > 5899 11:08:20.138646 mmap(NULL, 266240, PROT_READ|PROT_WRITE, > > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b380000 <0.000013> > > 5899 11:08:20.138793 mmap(NULL, 266240, PROT_READ|PROT_WRITE, > > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b33f000 <0.000009> > > > I don't know who call `futex`, and why waste such long time. This trace doesn't show enough info to say what is happening - a futex is just the syscall used for mutex locking, so that just shows that thread 5900 is waiting for some lock. This doesn't imply the time is wasted, or really saying anything useful at all. Meanwhile thread 5899 was doing some mmap calls. There's no obvious relationship between the times in thread 5900 and 58909 in this trace. The 9 second gap here is just coincidental. Regards, Daniel -- |: https://berrange.com -o- https://www.flickr.com/photos/dberrange :| |: https://libvirt.org -o- https://fstop138.berrange.com :| |: https://entangle-photo.org -o- https://www.instagram.com/dberrange :| ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Qemu-devel] Fwd: [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? 2017-06-19 9:45 ` Daniel P. Berrange @ 2017-06-20 2:23 ` Sam 0 siblings, 0 replies; 8+ messages in thread From: Sam @ 2017-06-20 2:23 UTC (permalink / raw) To: Daniel P. Berrange; +Cc: qemu-devel, qemu-discuss OK, Grub is bellow, which use huge page 1G. linux16 /boot/vmlinuz-0-rescue-1324ca4d8099476d99a8633e7cb952b7 > root=UUID=9c3cf5ff-7c35-40c4-a6d9-0fc67683c4ed ro crashkernel=auto rhgb > quiet default_hugepagesz=1G hugepagesz=1G hugepages=112, isolcpus=2,18 this is command line, ddc979cd is vhostuser interface connect with ovs-dpdk. For normal ovs, which is not ovs-dpdk, start time is 2 second, and there is no dpdk vhost user interface. For ovs-dpdk, start time is 15+ second, and there is dpdk vhost user interface. CMD="$QEMU_CMD -enable-kvm -cpu > qemu64,+vmx,+ssse3,+sse4.1,+sse4.2,+x2apic,+aes,+avx,+vme,+pat,+ss,+pclmulqdq,+xsave,level=13 > -machine pc,accel=kvm -chardev > socket,id=hmqmondev,port=55902,host=127.0.0.1,nodelay,server,nowait -mon > chardev=hmqmondev,id=hmqmon,mode=readline -rtc > base=utc,clock=host,driftfix=none -usb -device usb-tablet -daemonize > -nodefaults -nodefconfig -no-kvm-pit-reinjection -global > kvm-pit.lost_tick_policy=discard -vga std -k en-us -smp 8 -name test-name-5 > -m 40960 -boot order=cdn -vnc :2,password -drive > file=$DISK_0,if=none,id=drive_0,format=qcow2,cache=none,aio=native -device > virtio-blk-pci,id=dev_drive_0,drive=drive_0,bus=pci.0,addr=0x5 -drive > file=$DISK_1,if=none,id=drive_1,format=qcow2,cache=none,aio=native -device > virtio-blk-pci,id=dev_drive_1,drive=drive_1,bus=pci.0,addr=0x6 -drive > file=$DISK_2,if=none,id=drive_2,format=qcow2,cache=none,aio=native -device > virtio-blk-pci,id=dev_drive_2,drive=drive_2,bus=pci.0,addr=0x7 -device > ide-cd,drive=ide0-cd0,bus=ide.1,unit=1 -drive > id=ide0-cd0,media=cdrom,if=none -chardev > socket,id=char-n-ddc979cd,path=/usr/local/var/run/openvswitch/n-ddc979cd,server > -netdev type=vhost-user,id=n-ddc979cd,chardev=char-n-ddc979cd,vhostforce=on > -device > virtio-net-pci,netdev=n-ddc979cd,mac=00:22:dd:c9:79:cd,id=netdev-n-ddc979cd,addr=0xf$(nic_speed > 10000) -object > memory-backend-file,id=mem,size=40960M,mem-path=/mnt/huge,share=on -numa > node,memdev=mem -mem-prealloc -pidfile $PID_FILE -chardev > socket,path=/opt/cloud/workspace/servers/b2cebb02-d171-4929-95d6-61e54cd647f7/qga.sock,server,nowait,id=qga0 > -device virtio-serial -device > virtserialport,chardev=qga0,name=org.qemu.guest_agent.0" $QEMU_CMD is qemu binary file like 'qemu-system-x86_64_2.6.0'. BTW, when I only start ovs-dpdk in huge page enviroment, ovs-dpdk start time is also longer then normal ovs, and it is hang in EAL initializition and seetting up physical contiguous memory, log like this: EAL: Setting up physically contiguous memory... But qemu don't need EAL initilizition, that's the question I can't figure out. And qemu long time start up only happened in huge page enviroment, I don't know why. 2017-06-19 17:45 GMT+08:00 Daniel P. Berrange <berrange@redhat.com>: > On Mon, Jun 19, 2017 at 05:30:59PM +0800, Sam wrote: > > Hi all, > > > > I'm running `QEMU_CMD ...` to create a vm under dpdk huge page envriment > > (which set huge page 1G). And I enable all events in qemu. > > Please provide the full QEMU command line you are using. > > > For qemu and ovs-dpdk(ovs-2.4.9 with dpdk-2.2.0) environment, detail log > is: > > > > > 30012@1497443246.678304:object_dynamic_cast_assert > > qemu:memory-region->qemu:memory-region (/home/hu > > > anghuai/cloud/contrib/qemu-2.6.0/memory.c:1076:memory_region_initfn) > > > 30012@1497443256.274866:object_dynamic_cast_assert > > qio-channel-socket->qio-channel-socket (io/chann > > > el-socket.c:389:qio_channel_socket_init) > > > > > > I don't know why qemu doing 'memory_region_initfn' function in this 10 > > second, does anyone know this? > > If memory initialization takes a long time, this is likely a result of > QEMU pre-allocating the memory pages, which is a fairly slow procedure, > that can have noticable startup time impact for guests with large RAM > > > > static void memory_region_initfn(Object *obj) > > > { > > > MemoryRegion *mr = MEMORY_REGION(obj); > > > ObjectProperty *op; > > > mr->ops = &unassigned_mem_ops; > > > mr->enabled = true; > > > mr->romd_mode = true; > > > mr->global_locking = true; > > > mr->destructor = memory_region_destructor_none; > > > QTAILQ_INIT(&mr->subregions); > > > QTAILQ_INIT(&mr->coalesced); > > > op = object_property_add(OBJECT(mr), "container", > > > "link<" TYPE_MEMORY_REGION ">", > > > memory_region_get_container, > > > NULL, /* memory_region_set_container */ > > > NULL, NULL, &error_abort); > > > op->resolve = memory_region_resolve_container; > > > object_property_add(OBJECT(mr), "addr", "uint64", > > > memory_region_get_addr, > > > NULL, /* memory_region_set_addr */ > > > NULL, NULL, &error_abort); > > > object_property_add(OBJECT(mr), "priority", "uint32", > > > memory_region_get_priority, > > > NULL, /* memory_region_set_priority */ > > > NULL, NULL, &error_abort); > > > object_property_add_bool(OBJECT(mr), "may-overlap", > > > memory_region_get_may_overlap, > > > NULL, /* memory_region_set_may_overlap */ > > > &error_abort); > > > object_property_add(OBJECT(mr), "size", "uint64", > > > memory_region_get_size, > > > NULL, /* memory_region_set_size, */ > > > NULL, NULL, &error_abort); > > > } > > > > > > I print all system call by `strace -f -T -tt -e trace=all -o output.txt > > $QEMU_CMD`, and I found this: > > > > 5900 11:08:11.288701 nanosleep({0, 10000000}, 0x7ff103c13a80) = 0 > > > <0.010171> > > > 5900 11:08:11.299052 futex(0x7ff10be24340, FUTEX_WAIT_PRIVATE, 2, NULL > > > <unfinished ...> > > > 5899 11:08:20.138492 rt_sigaction(SIGBUS, {0x7ff10b5b1040, [], > > > SA_RESTORER|SA_SIGINFO, 0x7ff1085fd100}, NULL, 8) = 0 <0.000012> > > > 5899 11:08:20.138598 rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], > > > NULL, 8) = 0 <0.000008> > > > 5899 11:08:20.138646 mmap(NULL, 266240, PROT_READ|PROT_WRITE, > > > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b380000 <0.000013> > > > 5899 11:08:20.138793 mmap(NULL, 266240, PROT_READ|PROT_WRITE, > > > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff10b33f000 <0.000009> > > > > > > I don't know who call `futex`, and why waste such long time. > > This trace doesn't show enough info to say what is happening - a futex > is just the syscall used for mutex locking, so that just shows that > thread 5900 is waiting for some lock. This doesn't imply the time is > wasted, or really saying anything useful at all. > > Meanwhile thread 5899 was doing some mmap calls. There's no obvious > relationship between the times in thread 5900 and 58909 in this trace. > The 9 second gap here is just coincidental. > > Regards, > Daniel > -- > |: https://berrange.com -o- https://www.flickr.com/photos/ > dberrange :| > |: https://libvirt.org -o- > https://fstop138.berrange.com :| > |: https://entangle-photo.org -o- https://www.instagram.com/ > dberrange :| > ^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2017-06-20 2:23 UTC | newest] Thread overview: 8+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2017-06-16 8:11 [DPDK-memory] how qemu waste such long time under dpdk huge page envriment? Sam 2017-06-16 8:26 ` Sam 2017-06-16 8:59 ` Bruce Richardson 2017-06-19 3:12 ` Sam 2017-06-19 3:13 ` Sam 2017-06-19 9:30 ` [Qemu-devel] Fwd: " Sam 2017-06-19 9:45 ` Daniel P. Berrange 2017-06-20 2:23 ` Sam
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.