Re: [osv-dev] Re: OOM query

2020-03-22 Thread Rick Payne
On Sun, 2020-03-22 at 22:08 -0700, Waldek Kozaczuk wrote:
> 
> 
> On Monday, March 23, 2020 at 12:36:52 AM UTC-4, rickp wrote:
> > Looks to me like its trying to allocate 40MB but the available
> > memory 
> > is 10GB, surely? 10933128KB is 10,933MB 
> > 
> 
> I misread the number - forgot about 1K.
> 
> Any chance you could run the app outside of production with memory
> tracing enabled - 
> https://github.com/cloudius-systems/osv/wiki/Trace-analysis-using-trace.py#tracing-memory-allocations
>  (without --trace-backtrace) for while? And then we can have a better
> sense of what kind of allocations it makes. The output of trace
> memory-analyzer would be really helpful.

I can certainly run that local with locally generated workloads, which
should be close enough - but we've never managed to trigger the oom
condition that way (other than by really constraining the memory
artificially). It should be close enough though - let me see what I can
do.

Rick


-- 
You received this message because you are subscribed to the Google Groups "OSv 
Development" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to osv-dev+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/osv-dev/77725fd3d095c86e37648713ab4bd3185a496500.camel%40rossfell.co.uk.


Re: [osv-dev] Re: OOM query

2020-03-22 Thread Waldek Kozaczuk
Based on what I can tell the available remaining memory seems to be heavily 
fragmented (I have no idea why). If it is it would help to implement 
https://github.com/cloudius-systems/osv/issues/854 which I will give it a 
try. Hopefully, I can have a patch within a day.

On Monday, March 23, 2020 at 1:08:22 AM UTC-4, Waldek Kozaczuk wrote:
>
>
>
> On Monday, March 23, 2020 at 12:36:52 AM UTC-4, rickp wrote:
>
>
> Looks to me like its trying to allocate 40MB but the available memory 
> is 10GB, surely? 10933128KB is 10,933MB 
>
> I misread the number - forgot about 1K.
>
> Any chance you could run the app outside of production with memory tracing 
> enabled - 
> https://github.com/cloudius-systems/osv/wiki/Trace-analysis-using-trace.py#tracing-memory-allocations
>  (without --trace-backtrace) for while? And then we can have a better 
> sense of what kind of allocations it makes. The output of trace 
> memory-analyzer would be really helpful.
>
>
> Its probably erlang garbage collection, but it seems very strange to me 
> as sometimes it happens very quickly after we start the system. There's 
> no way we're allocate more memory than the system ever claims to have - 
> so if it is fragmentation, why do we do so poor compared to the linux 
> kernel? 
>
> Is anyone else running VMs based on OSv for more than a few days? 
>
> Rick 
>
> On Sun, 2020-03-22 at 18:01 -0700, Waldek Kozaczuk wrote: 
> > Either way, it looks like the app is trying to allocate almost 40MB 
> > and the remaining memory is ~ 10MB. So, in this case, there is no 
> > surprise, is there? 
> > 
> > In the previous case, you reported there were two threads each 
> > requesting ~5MB and there was plenty of memory. If I understand the 
> > code correctly the remaining memory must have been fragmented and 
> > there was no big enough free page range. 
> > 
> > On Sunday, March 22, 2020 at 8:31:01 PM UTC-4, Waldek Kozaczuk wrote: 
> > > It does for me. Are you using the latest version of this script 
> > > from master? I think there were couple of things I changed there 
> > > recently as part of wide upgrade to Python 3. 
> > > 
> > > On Sun, Mar 22, 2020 at 20:27 Rick Payne  
> > > wrote: 
> > > > Does that command work for you? For me I get: 
> > > > 
> > > > (gdb) osv heap 
> > > > Python Exception  %x format: an integer is 
> > > > required, 
> > > > not gdb.Value: 
> > > > Error occurred in Python command: %x format: an integer is 
> > > > required, 
> > > > not gdb.Value 
> > > > 
> > > > Rick 
> > > > 
> > > > On Sun, 2020-03-22 at 19:37 -0400, Waldek Kozaczuk wrote: 
> > > > > Can you run ‘osv heap’ from gdb at this point? 
> > > > > 
> > > > > On Sun, Mar 22, 2020 at 19:31 Rick Payne  
> > > > > wrote: 
> > > > > > Ok, so i applied the patch, and the printf and this is what I 
> > > > see: 
> > > > > > 
> > > > > > page_range_allocator: no ranges found for size 39849984 and 
> > > > exact 
> > > > > > order: 14 
> > > > > > Waiter: 1_scheduler, bytes: 39849984 
> > > > > > Out of memory: could not reclaim any further. Current memory: 
> > > > > > 10933128 
> > > > > > Kb, target: 0 Kb 
> > > > > > 
> > > > > > Rick 
> > > > > > 
> > > > > > On Sat, 2020-03-21 at 21:16 -0700, Waldek Kozaczuk wrote: 
> > > > > > > 
> > > > > > > 
> > > > > > > I think that OSv might be hitting some sort of 
> > > > fragmentation 
> > > > > > scenario 
> > > > > > > (another question is why we get to this point) which should 
> > > > be 
> > > > > > > handled but is not due to the bug this patch fixes: 
> > > > > > > 
> > > > > > > diff --git a/core/mempool.cc b/core/mempool.cc 
> > > > > > > index d902eea8..11fd1456 100644 
> > > > > > > --- a/core/mempool.cc 
> > > > > > > +++ b/core/mempool.cc 
> > > > > > > @@ -702,10 +702,13 @@ page_range* 
> > > > > > page_range_allocator::alloc(size_t 
> > > > > > > size) 
> > > > > > >  for (auto&& pr : _free[exact_order - 1]) { 
> > > > > > >  if (pr.size >= size) { 
> > > > > > >  range =  
> > > > > > > +remove_list(exact_order - 1, *range); 
> > > > > > >  break; 
> > > > > > >  } 
> > > > > > >  } 
> > > > > > > -return nullptr; 
> > > > > > > +if (!range) { 
> > > > > > > +return nullptr; 
> > > > > > > +} 
> > > > > > >  } else if (order == max_order) { 
> > > > > > >  range = &*_free_huge.rbegin(); 
> > > > > > >  if (range->size < size) { 
> > > > > > > 
> > > > > > > Can you give it a try and see what happens with this patch? 
> > > > > > > 
> > > > > > > Waldek 
> > > > > > > 
> > > > > > > PS. You might also add this printout to verify if you are 
> > > > hitting 
> > > > > > the 
> > > > > > > hard fragmentation case: 
> > > > > > > 
> > > > > > >  page_range* range = nullptr; 
> > > > > > >  if (!bitset) { 
> > > > > > >  if (!exact_order || _free[exact_order - 
> > > > 1].empty()) { 
> > > > > > > +printf("page_range_allocator: no 

Re: [osv-dev] Re: OOM query

2020-03-22 Thread Waldek Kozaczuk


On Monday, March 23, 2020 at 12:36:52 AM UTC-4, rickp wrote:
>
>
> Looks to me like its trying to allocate 40MB but the available memory 
> is 10GB, surely? 10933128KB is 10,933MB 
>
> I misread the number - forgot about 1K.

Any chance you could run the app outside of production with memory tracing 
enabled - 
https://github.com/cloudius-systems/osv/wiki/Trace-analysis-using-trace.py#tracing-memory-allocations
 (without --trace-backtrace) for while? And then we can have a better sense 
of what kind of allocations it makes. The output of trace memory-analyzer would 
be really helpful.


Its probably erlang garbage collection, but it seems very strange to me 
> as sometimes it happens very quickly after we start the system. There's 
> no way we're allocate more memory than the system ever claims to have - 
> so if it is fragmentation, why do we do so poor compared to the linux 
> kernel? 
>
> Is anyone else running VMs based on OSv for more than a few days? 
>
> Rick 
>
> On Sun, 2020-03-22 at 18:01 -0700, Waldek Kozaczuk wrote: 
> > Either way, it looks like the app is trying to allocate almost 40MB 
> > and the remaining memory is ~ 10MB. So, in this case, there is no 
> > surprise, is there? 
> > 
> > In the previous case, you reported there were two threads each 
> > requesting ~5MB and there was plenty of memory. If I understand the 
> > code correctly the remaining memory must have been fragmented and 
> > there was no big enough free page range. 
> > 
> > On Sunday, March 22, 2020 at 8:31:01 PM UTC-4, Waldek Kozaczuk wrote: 
> > > It does for me. Are you using the latest version of this script 
> > > from master? I think there were couple of things I changed there 
> > > recently as part of wide upgrade to Python 3. 
> > > 
> > > On Sun, Mar 22, 2020 at 20:27 Rick Payne  > 
> > > wrote: 
> > > > Does that command work for you? For me I get: 
> > > > 
> > > > (gdb) osv heap 
> > > > Python Exception  %x format: an integer is 
> > > > required, 
> > > > not gdb.Value: 
> > > > Error occurred in Python command: %x format: an integer is 
> > > > required, 
> > > > not gdb.Value 
> > > > 
> > > > Rick 
> > > > 
> > > > On Sun, 2020-03-22 at 19:37 -0400, Waldek Kozaczuk wrote: 
> > > > > Can you run ‘osv heap’ from gdb at this point? 
> > > > > 
> > > > > On Sun, Mar 22, 2020 at 19:31 Rick Payne  > 
> > > > > wrote: 
> > > > > > Ok, so i applied the patch, and the printf and this is what I 
> > > > see: 
> > > > > > 
> > > > > > page_range_allocator: no ranges found for size 39849984 and 
> > > > exact 
> > > > > > order: 14 
> > > > > > Waiter: 1_scheduler, bytes: 39849984 
> > > > > > Out of memory: could not reclaim any further. Current memory: 
> > > > > > 10933128 
> > > > > > Kb, target: 0 Kb 
> > > > > > 
> > > > > > Rick 
> > > > > > 
> > > > > > On Sat, 2020-03-21 at 21:16 -0700, Waldek Kozaczuk wrote: 
> > > > > > > 
> > > > > > > 
> > > > > > > I think that OSv might be hitting some sort of 
> > > > fragmentation 
> > > > > > scenario 
> > > > > > > (another question is why we get to this point) which should 
> > > > be 
> > > > > > > handled but is not due to the bug this patch fixes: 
> > > > > > > 
> > > > > > > diff --git a/core/mempool.cc b/core/mempool.cc 
> > > > > > > index d902eea8..11fd1456 100644 
> > > > > > > --- a/core/mempool.cc 
> > > > > > > +++ b/core/mempool.cc 
> > > > > > > @@ -702,10 +702,13 @@ page_range* 
> > > > > > page_range_allocator::alloc(size_t 
> > > > > > > size) 
> > > > > > >  for (auto&& pr : _free[exact_order - 1]) { 
> > > > > > >  if (pr.size >= size) { 
> > > > > > >  range =  
> > > > > > > +remove_list(exact_order - 1, *range); 
> > > > > > >  break; 
> > > > > > >  } 
> > > > > > >  } 
> > > > > > > -return nullptr; 
> > > > > > > +if (!range) { 
> > > > > > > +return nullptr; 
> > > > > > > +} 
> > > > > > >  } else if (order == max_order) { 
> > > > > > >  range = &*_free_huge.rbegin(); 
> > > > > > >  if (range->size < size) { 
> > > > > > > 
> > > > > > > Can you give it a try and see what happens with this patch? 
> > > > > > > 
> > > > > > > Waldek 
> > > > > > > 
> > > > > > > PS. You might also add this printout to verify if you are 
> > > > hitting 
> > > > > > the 
> > > > > > > hard fragmentation case: 
> > > > > > > 
> > > > > > >  page_range* range = nullptr; 
> > > > > > >  if (!bitset) { 
> > > > > > >  if (!exact_order || _free[exact_order - 
> > > > 1].empty()) { 
> > > > > > > +printf("page_range_allocator: no ranges found 
> > > > for 
> > > > > > size 
> > > > > > > %ld and exact order: %d\n", size, exact_order); 
> > > > > > >  return nullptr; 
> > > > > > >  } 
> > > > > > > 
> > > > > > > On Saturday, March 21, 2020 at 7:17:16 PM UTC-4, rickp 
> > > > wrote: 
> > > > > > > > Ok, with the waiter_print, we see: 
> > > > > > > > 
> > > > > > 

Re: [osv-dev] Re: OOM query

2020-03-22 Thread Rick Payne


Looks to me like its trying to allocate 40MB but the available memory
is 10GB, surely? 10933128KB is 10,933MB

Its probably erlang garbage collection, but it seems very strange to me
as sometimes it happens very quickly after we start the system. There's
no way we're allocate more memory than the system ever claims to have -
so if it is fragmentation, why do we do so poor compared to the linux
kernel?

Is anyone else running VMs based on OSv for more than a few days?

Rick

On Sun, 2020-03-22 at 18:01 -0700, Waldek Kozaczuk wrote:
> Either way, it looks like the app is trying to allocate almost 40MB
> and the remaining memory is ~ 10MB. So, in this case, there is no
> surprise, is there?
> 
> In the previous case, you reported there were two threads each
> requesting ~5MB and there was plenty of memory. If I understand the
> code correctly the remaining memory must have been fragmented and
> there was no big enough free page range.
> 
> On Sunday, March 22, 2020 at 8:31:01 PM UTC-4, Waldek Kozaczuk wrote:
> > It does for me. Are you using the latest version of this script
> > from master? I think there were couple of things I changed there
> > recently as part of wide upgrade to Python 3. 
> > 
> > On Sun, Mar 22, 2020 at 20:27 Rick Payne 
> > wrote:
> > > Does that command work for you? For me I get:
> > > 
> > > (gdb) osv heap
> > > Python Exception  %x format: an integer is
> > > required,
> > > not gdb.Value: 
> > > Error occurred in Python command: %x format: an integer is
> > > required, 
> > > not gdb.Value
> > > 
> > > Rick
> > > 
> > > On Sun, 2020-03-22 at 19:37 -0400, Waldek Kozaczuk wrote:
> > > > Can you run ‘osv heap’ from gdb at this point?
> > > > 
> > > > On Sun, Mar 22, 2020 at 19:31 Rick Payne 
> > > > wrote:
> > > > > Ok, so i applied the patch, and the printf and this is what I
> > > see:
> > > > > 
> > > > > page_range_allocator: no ranges found for size 39849984 and
> > > exact
> > > > > order: 14
> > > > > Waiter: 1_scheduler, bytes: 39849984
> > > > > Out of memory: could not reclaim any further. Current memory:
> > > > > 10933128
> > > > > Kb, target: 0 Kb
> > > > > 
> > > > > Rick
> > > > > 
> > > > > On Sat, 2020-03-21 at 21:16 -0700, Waldek Kozaczuk wrote:
> > > > > > 
> > > > > > 
> > > > > > I think that OSv might be hitting some sort of
> > > fragmentation
> > > > > scenario
> > > > > > (another question is why we get to this point) which should
> > > be
> > > > > > handled but is not due to the bug this patch fixes:
> > > > > > 
> > > > > > diff --git a/core/mempool.cc b/core/mempool.cc
> > > > > > index d902eea8..11fd1456 100644
> > > > > > --- a/core/mempool.cc
> > > > > > +++ b/core/mempool.cc
> > > > > > @@ -702,10 +702,13 @@ page_range*
> > > > > page_range_allocator::alloc(size_t
> > > > > > size)
> > > > > >  for (auto&& pr : _free[exact_order - 1]) {
> > > > > >  if (pr.size >= size) {
> > > > > >  range = 
> > > > > > +remove_list(exact_order - 1, *range);
> > > > > >  break;
> > > > > >  }
> > > > > >  }
> > > > > > -return nullptr;
> > > > > > +if (!range) {
> > > > > > +return nullptr;
> > > > > > +}
> > > > > >  } else if (order == max_order) {
> > > > > >  range = &*_free_huge.rbegin();
> > > > > >  if (range->size < size) {
> > > > > > 
> > > > > > Can you give it a try and see what happens with this patch?
> > > > > > 
> > > > > > Waldek
> > > > > > 
> > > > > > PS. You might also add this printout to verify if you are
> > > hitting
> > > > > the
> > > > > > hard fragmentation case:
> > > > > > 
> > > > > >  page_range* range = nullptr;
> > > > > >  if (!bitset) {
> > > > > >  if (!exact_order || _free[exact_order -
> > > 1].empty()) {
> > > > > > +printf("page_range_allocator: no ranges found
> > > for
> > > > > size
> > > > > > %ld and exact order: %d\n", size, exact_order);
> > > > > >  return nullptr;
> > > > > >  }
> > > > > > 
> > > > > > On Saturday, March 21, 2020 at 7:17:16 PM UTC-4, rickp
> > > wrote:
> > > > > > > Ok, with the waiter_print, we see: 
> > > > > > > 
> > > > > > > Waiter: 2_scheduler, bytes: 4984832 
> > > > > > > Waiter: 5_scheduler, bytes: 4984832 
> > > > > > > Out of memory: could not reclaim any further. Current
> > > memory: 
> > > > > > > 10871576Kb, target: 0 Kb 
> > > > > > > 
> > > > > > > 'osv mem' in gdb reports loads of free memory: 
> > > > > > > 
> > > > > > > (gdb) osv mem 
> > > > > > > Total Memory: 12884372480 Bytes 
> > > > > > > Mmap Memory:  1610067968 Bytes (12.50%) 
> > > > > > > Free Memory:  11132493824 Bytes (86.40%) 
> > > > > > > 
> > > > > > > So why is it failing to allocate 5MB when it claims to
> > > have
> > > > > 11GB
> > > > > > > free? 
> > > > > > > 
> > > > > > > Any more debug I can provide? 
> > > > > > > 
> > > > > > > Rick 
> > > > > > > 
> > > > > > > On Sat, 2020-03-21 at 15:32 +1000, Rick Payne 

Re: [osv-dev] Re: OOM query

2020-03-22 Thread Waldek Kozaczuk
Do you know if the application uses "huge" (>=2MB) malloc? I found this 
relevant discussion - 
https://groups.google.com/d/msg/osv-dev/uLoxcjU164k/WWl6dMzsCAAJ - about 
how OSv currently uses contiguous physical memory areas to back these kinds 
of requests. 

There is an open issue about that - 
https://github.com/cloudius-systems/osv/issues/854. It should not be 
difficult to implement it.

It would be nice to confirm that memory is indeed fragmented in your case.

On Sunday, March 22, 2020 at 9:01:26 PM UTC-4, Waldek Kozaczuk wrote:
>
> Either way, it looks like the app is trying to allocate almost 40MB and 
> the remaining memory is ~ 10MB. So, in this case, there is no surprise, is 
> there?
>
> In the previous case, you reported there were two threads each requesting 
> ~5MB and there was plenty of memory. If I understand the code correctly the 
> remaining memory must have been fragmented and there was no big enough free 
> page range.
>
> On Sunday, March 22, 2020 at 8:31:01 PM UTC-4, Waldek Kozaczuk wrote:
>>
>> It does for me. Are you using the latest version of this script from 
>> master? I think there were couple of things I changed there recently as 
>> part of wide upgrade to Python 3. 
>>
>> On Sun, Mar 22, 2020 at 20:27 Rick Payne  wrote:
>>
>>>
>>> Does that command work for you? For me I get:
>>>
>>> (gdb) osv heap
>>> Python Exception  %x format: an integer is required,
>>> not gdb.Value: 
>>> Error occurred in Python command: %x format: an integer is required, 
>>> not gdb.Value
>>>
>>> Rick
>>>
>>> On Sun, 2020-03-22 at 19:37 -0400, Waldek Kozaczuk wrote:
>>> > Can you run ‘osv heap’ from gdb at this point?
>>> > 
>>> > On Sun, Mar 22, 2020 at 19:31 Rick Payne 
>>> > wrote:
>>> > > Ok, so i applied the patch, and the printf and this is what I see:
>>> > > 
>>> > > page_range_allocator: no ranges found for size 39849984 and exact
>>> > > order: 14
>>> > > Waiter: 1_scheduler, bytes: 39849984
>>> > > Out of memory: could not reclaim any further. Current memory:
>>> > > 10933128
>>> > > Kb, target: 0 Kb
>>> > > 
>>> > > Rick
>>> > > 
>>> > > On Sat, 2020-03-21 at 21:16 -0700, Waldek Kozaczuk wrote:
>>> > > > 
>>> > > > 
>>> > > > I think that OSv might be hitting some sort of fragmentation
>>> > > scenario
>>> > > > (another question is why we get to this point) which should be
>>> > > > handled but is not due to the bug this patch fixes:
>>> > > > 
>>> > > > diff --git a/core/mempool.cc b/core/mempool.cc
>>> > > > index d902eea8..11fd1456 100644
>>> > > > --- a/core/mempool.cc
>>> > > > +++ b/core/mempool.cc
>>> > > > @@ -702,10 +702,13 @@ page_range*
>>> > > page_range_allocator::alloc(size_t
>>> > > > size)
>>> > > >  for (auto&& pr : _free[exact_order - 1]) {
>>> > > >  if (pr.size >= size) {
>>> > > >  range = 
>>> > > > +remove_list(exact_order - 1, *range);
>>> > > >  break;
>>> > > >  }
>>> > > >  }
>>> > > > -return nullptr;
>>> > > > +if (!range) {
>>> > > > +return nullptr;
>>> > > > +}
>>> > > >  } else if (order == max_order) {
>>> > > >  range = &*_free_huge.rbegin();
>>> > > >  if (range->size < size) {
>>> > > > 
>>> > > > Can you give it a try and see what happens with this patch?
>>> > > > 
>>> > > > Waldek
>>> > > > 
>>> > > > PS. You might also add this printout to verify if you are hitting
>>> > > the
>>> > > > hard fragmentation case:
>>> > > > 
>>> > > >  page_range* range = nullptr;
>>> > > >  if (!bitset) {
>>> > > >  if (!exact_order || _free[exact_order - 1].empty()) {
>>> > > > +printf("page_range_allocator: no ranges found for
>>> > > size
>>> > > > %ld and exact order: %d\n", size, exact_order);
>>> > > >  return nullptr;
>>> > > >  }
>>> > > > 
>>> > > > On Saturday, March 21, 2020 at 7:17:16 PM UTC-4, rickp wrote:
>>> > > > > Ok, with the waiter_print, we see: 
>>> > > > > 
>>> > > > > Waiter: 2_scheduler, bytes: 4984832 
>>> > > > > Waiter: 5_scheduler, bytes: 4984832 
>>> > > > > Out of memory: could not reclaim any further. Current memory: 
>>> > > > > 10871576Kb, target: 0 Kb 
>>> > > > > 
>>> > > > > 'osv mem' in gdb reports loads of free memory: 
>>> > > > > 
>>> > > > > (gdb) osv mem 
>>> > > > > Total Memory: 12884372480 Bytes 
>>> > > > > Mmap Memory:  1610067968 Bytes (12.50%) 
>>> > > > > Free Memory:  11132493824 Bytes (86.40%) 
>>> > > > > 
>>> > > > > So why is it failing to allocate 5MB when it claims to have
>>> > > 11GB
>>> > > > > free? 
>>> > > > > 
>>> > > > > Any more debug I can provide? 
>>> > > > > 
>>> > > > > Rick 
>>> > > > > 
>>> > > > > On Sat, 2020-03-21 at 15:32 +1000, Rick Payne wrote: 
>>> > > > > > And indeed, back on the 'release' image, and we hit an oom: 
>>> > > > > > 
>>> > > > > > (gdb) b memory::oom 
>>> > > > > > Breakpoint 1 at 0x403ee300: file core/mempool.cc, line 505. 
>>> > > > > > (gdb) c 
>>> > > > > > Continuing. 

Re: [osv-dev] Re: OOM query

2020-03-22 Thread Waldek Kozaczuk
Either way, it looks like the app is trying to allocate almost 40MB and the 
remaining memory is ~ 10MB. So, in this case, there is no surprise, is 
there?

In the previous case, you reported there were two threads each requesting 
~5MB and there was plenty of memory. If I understand the code correctly the 
remaining memory must have been fragmented and there was no big enough free 
page range.

On Sunday, March 22, 2020 at 8:31:01 PM UTC-4, Waldek Kozaczuk wrote:
>
> It does for me. Are you using the latest version of this script from 
> master? I think there were couple of things I changed there recently as 
> part of wide upgrade to Python 3. 
>
> On Sun, Mar 22, 2020 at 20:27 Rick Payne  wrote:
>
>>
>> Does that command work for you? For me I get:
>>
>> (gdb) osv heap
>> Python Exception  %x format: an integer is required,
>> not gdb.Value: 
>> Error occurred in Python command: %x format: an integer is required, 
>> not gdb.Value
>>
>> Rick
>>
>> On Sun, 2020-03-22 at 19:37 -0400, Waldek Kozaczuk wrote:
>> > Can you run ‘osv heap’ from gdb at this point?
>> > 
>> > On Sun, Mar 22, 2020 at 19:31 Rick Payne 
>> > wrote:
>> > > Ok, so i applied the patch, and the printf and this is what I see:
>> > > 
>> > > page_range_allocator: no ranges found for size 39849984 and exact
>> > > order: 14
>> > > Waiter: 1_scheduler, bytes: 39849984
>> > > Out of memory: could not reclaim any further. Current memory:
>> > > 10933128
>> > > Kb, target: 0 Kb
>> > > 
>> > > Rick
>> > > 
>> > > On Sat, 2020-03-21 at 21:16 -0700, Waldek Kozaczuk wrote:
>> > > > 
>> > > > 
>> > > > I think that OSv might be hitting some sort of fragmentation
>> > > scenario
>> > > > (another question is why we get to this point) which should be
>> > > > handled but is not due to the bug this patch fixes:
>> > > > 
>> > > > diff --git a/core/mempool.cc b/core/mempool.cc
>> > > > index d902eea8..11fd1456 100644
>> > > > --- a/core/mempool.cc
>> > > > +++ b/core/mempool.cc
>> > > > @@ -702,10 +702,13 @@ page_range*
>> > > page_range_allocator::alloc(size_t
>> > > > size)
>> > > >  for (auto&& pr : _free[exact_order - 1]) {
>> > > >  if (pr.size >= size) {
>> > > >  range = 
>> > > > +remove_list(exact_order - 1, *range);
>> > > >  break;
>> > > >  }
>> > > >  }
>> > > > -return nullptr;
>> > > > +if (!range) {
>> > > > +return nullptr;
>> > > > +}
>> > > >  } else if (order == max_order) {
>> > > >  range = &*_free_huge.rbegin();
>> > > >  if (range->size < size) {
>> > > > 
>> > > > Can you give it a try and see what happens with this patch?
>> > > > 
>> > > > Waldek
>> > > > 
>> > > > PS. You might also add this printout to verify if you are hitting
>> > > the
>> > > > hard fragmentation case:
>> > > > 
>> > > >  page_range* range = nullptr;
>> > > >  if (!bitset) {
>> > > >  if (!exact_order || _free[exact_order - 1].empty()) {
>> > > > +printf("page_range_allocator: no ranges found for
>> > > size
>> > > > %ld and exact order: %d\n", size, exact_order);
>> > > >  return nullptr;
>> > > >  }
>> > > > 
>> > > > On Saturday, March 21, 2020 at 7:17:16 PM UTC-4, rickp wrote:
>> > > > > Ok, with the waiter_print, we see: 
>> > > > > 
>> > > > > Waiter: 2_scheduler, bytes: 4984832 
>> > > > > Waiter: 5_scheduler, bytes: 4984832 
>> > > > > Out of memory: could not reclaim any further. Current memory: 
>> > > > > 10871576Kb, target: 0 Kb 
>> > > > > 
>> > > > > 'osv mem' in gdb reports loads of free memory: 
>> > > > > 
>> > > > > (gdb) osv mem 
>> > > > > Total Memory: 12884372480 Bytes 
>> > > > > Mmap Memory:  1610067968 Bytes (12.50%) 
>> > > > > Free Memory:  11132493824 Bytes (86.40%) 
>> > > > > 
>> > > > > So why is it failing to allocate 5MB when it claims to have
>> > > 11GB
>> > > > > free? 
>> > > > > 
>> > > > > Any more debug I can provide? 
>> > > > > 
>> > > > > Rick 
>> > > > > 
>> > > > > On Sat, 2020-03-21 at 15:32 +1000, Rick Payne wrote: 
>> > > > > > And indeed, back on the 'release' image, and we hit an oom: 
>> > > > > > 
>> > > > > > (gdb) b memory::oom 
>> > > > > > Breakpoint 1 at 0x403ee300: file core/mempool.cc, line 505. 
>> > > > > > (gdb) c 
>> > > > > > Continuing. 
>> > > > > > 
>> > > > > > Thread 1 hit Breakpoint 1, memory::oom (target=target@entry=0
>> > > )
>> > > > > at 
>> > > > > > core/mempool.cc:505 
>> > > > > > 505 core/mempool.cc: No such file or directory. 
>> > > > > > (gdb) osv memory 
>> > > > > > Total Memory: 12884372480 Bytes 
>> > > > > > Mmap Memory:  1541332992 Bytes (11.96%) 
>> > > > > > Free Memory:  11490983936 Bytes (89.19%) 
>> > > > > > 
>> > > > > > I don't have the _waiters list print unforutnately (as I
>> > > hadn't 
>> > > > > > included it in this image). It looks like this though: 
>> > > > > > 
>> > > > > > (gdb) p _oom_blocked._waiters 
>> > > > > > $4 = 
>> > > > > >
>> > > > >
>> > > 

Re: [osv-dev] Re: OOM query

2020-03-22 Thread Waldek Kozaczuk
It does for me. Are you using the latest version of this script from
master? I think there were couple of things I changed there recently as
part of wide upgrade to Python 3.

On Sun, Mar 22, 2020 at 20:27 Rick Payne  wrote:

>
> Does that command work for you? For me I get:
>
> (gdb) osv heap
> Python Exception  %x format: an integer is required,
> not gdb.Value:
> Error occurred in Python command: %x format: an integer is required,
> not gdb.Value
>
> Rick
>
> On Sun, 2020-03-22 at 19:37 -0400, Waldek Kozaczuk wrote:
> > Can you run ‘osv heap’ from gdb at this point?
> >
> > On Sun, Mar 22, 2020 at 19:31 Rick Payne 
> > wrote:
> > > Ok, so i applied the patch, and the printf and this is what I see:
> > >
> > > page_range_allocator: no ranges found for size 39849984 and exact
> > > order: 14
> > > Waiter: 1_scheduler, bytes: 39849984
> > > Out of memory: could not reclaim any further. Current memory:
> > > 10933128
> > > Kb, target: 0 Kb
> > >
> > > Rick
> > >
> > > On Sat, 2020-03-21 at 21:16 -0700, Waldek Kozaczuk wrote:
> > > >
> > > >
> > > > I think that OSv might be hitting some sort of fragmentation
> > > scenario
> > > > (another question is why we get to this point) which should be
> > > > handled but is not due to the bug this patch fixes:
> > > >
> > > > diff --git a/core/mempool.cc b/core/mempool.cc
> > > > index d902eea8..11fd1456 100644
> > > > --- a/core/mempool.cc
> > > > +++ b/core/mempool.cc
> > > > @@ -702,10 +702,13 @@ page_range*
> > > page_range_allocator::alloc(size_t
> > > > size)
> > > >  for (auto&& pr : _free[exact_order - 1]) {
> > > >  if (pr.size >= size) {
> > > >  range = 
> > > > +remove_list(exact_order - 1, *range);
> > > >  break;
> > > >  }
> > > >  }
> > > > -return nullptr;
> > > > +if (!range) {
> > > > +return nullptr;
> > > > +}
> > > >  } else if (order == max_order) {
> > > >  range = &*_free_huge.rbegin();
> > > >  if (range->size < size) {
> > > >
> > > > Can you give it a try and see what happens with this patch?
> > > >
> > > > Waldek
> > > >
> > > > PS. You might also add this printout to verify if you are hitting
> > > the
> > > > hard fragmentation case:
> > > >
> > > >  page_range* range = nullptr;
> > > >  if (!bitset) {
> > > >  if (!exact_order || _free[exact_order - 1].empty()) {
> > > > +printf("page_range_allocator: no ranges found for
> > > size
> > > > %ld and exact order: %d\n", size, exact_order);
> > > >  return nullptr;
> > > >  }
> > > >
> > > > On Saturday, March 21, 2020 at 7:17:16 PM UTC-4, rickp wrote:
> > > > > Ok, with the waiter_print, we see:
> > > > >
> > > > > Waiter: 2_scheduler, bytes: 4984832
> > > > > Waiter: 5_scheduler, bytes: 4984832
> > > > > Out of memory: could not reclaim any further. Current memory:
> > > > > 10871576Kb, target: 0 Kb
> > > > >
> > > > > 'osv mem' in gdb reports loads of free memory:
> > > > >
> > > > > (gdb) osv mem
> > > > > Total Memory: 12884372480 Bytes
> > > > > Mmap Memory:  1610067968 Bytes (12.50%)
> > > > > Free Memory:  11132493824 Bytes (86.40%)
> > > > >
> > > > > So why is it failing to allocate 5MB when it claims to have
> > > 11GB
> > > > > free?
> > > > >
> > > > > Any more debug I can provide?
> > > > >
> > > > > Rick
> > > > >
> > > > > On Sat, 2020-03-21 at 15:32 +1000, Rick Payne wrote:
> > > > > > And indeed, back on the 'release' image, and we hit an oom:
> > > > > >
> > > > > > (gdb) b memory::oom
> > > > > > Breakpoint 1 at 0x403ee300: file core/mempool.cc, line 505.
> > > > > > (gdb) c
> > > > > > Continuing.
> > > > > >
> > > > > > Thread 1 hit Breakpoint 1, memory::oom (target=target@entry=0
> > > )
> > > > > at
> > > > > > core/mempool.cc:505
> > > > > > 505 core/mempool.cc: No such file or directory.
> > > > > > (gdb) osv memory
> > > > > > Total Memory: 12884372480 Bytes
> > > > > > Mmap Memory:  1541332992 Bytes (11.96%)
> > > > > > Free Memory:  11490983936 Bytes (89.19%)
> > > > > >
> > > > > > I don't have the _waiters list print unforutnately (as I
> > > hadn't
> > > > > > included it in this image). It looks like this though:
> > > > > >
> > > > > > (gdb) p _oom_blocked._waiters
> > > > > > $4 =
> > > > > >
> > > > >
> > > { > > > > cl
> > > > > > ai
> > > > > > mer_waiters::wait_node,
> > > > > boost::intrusive::list_node_traits,
> > > > > > (boost::intrusive::link_mode_type)1,
> > > boost::intrusive::dft_tag,
> > > > > 1>,
> > > > > > unsigned long, false, void>> = {static constant_time_size =
> > > > > false,
> > > > > > static stateful_value_traits = ,
> > > > > > static has_container_from_iterator = ,
> > > static
> > > > > > safemode_or_autounlink = true,
> > > > > > data_ =
> > > > > >
> > > > >
> > > { > > > > > boost::intrusive::list_node_traits,
> > > > > > (boost::intrusive::link_mode_type)1,
> > > boost::intrusive::dft_tag,
> > > > > 1>> =
> > > > > >
> > 

Re: [osv-dev] Re: OOM query

2020-03-22 Thread Rick Payne


Does that command work for you? For me I get:

(gdb) osv heap
Python Exception  %x format: an integer is required,
not gdb.Value: 
Error occurred in Python command: %x format: an integer is required, 
not gdb.Value

Rick

On Sun, 2020-03-22 at 19:37 -0400, Waldek Kozaczuk wrote:
> Can you run ‘osv heap’ from gdb at this point?
> 
> On Sun, Mar 22, 2020 at 19:31 Rick Payne 
> wrote:
> > Ok, so i applied the patch, and the printf and this is what I see:
> > 
> > page_range_allocator: no ranges found for size 39849984 and exact
> > order: 14
> > Waiter: 1_scheduler, bytes: 39849984
> > Out of memory: could not reclaim any further. Current memory:
> > 10933128
> > Kb, target: 0 Kb
> > 
> > Rick
> > 
> > On Sat, 2020-03-21 at 21:16 -0700, Waldek Kozaczuk wrote:
> > > 
> > > 
> > > I think that OSv might be hitting some sort of fragmentation
> > scenario
> > > (another question is why we get to this point) which should be
> > > handled but is not due to the bug this patch fixes:
> > > 
> > > diff --git a/core/mempool.cc b/core/mempool.cc
> > > index d902eea8..11fd1456 100644
> > > --- a/core/mempool.cc
> > > +++ b/core/mempool.cc
> > > @@ -702,10 +702,13 @@ page_range*
> > page_range_allocator::alloc(size_t
> > > size)
> > >  for (auto&& pr : _free[exact_order - 1]) {
> > >  if (pr.size >= size) {
> > >  range = 
> > > +remove_list(exact_order - 1, *range);
> > >  break;
> > >  }
> > >  }
> > > -return nullptr;
> > > +if (!range) {
> > > +return nullptr;
> > > +}
> > >  } else if (order == max_order) {
> > >  range = &*_free_huge.rbegin();
> > >  if (range->size < size) {
> > > 
> > > Can you give it a try and see what happens with this patch?
> > > 
> > > Waldek
> > > 
> > > PS. You might also add this printout to verify if you are hitting
> > the
> > > hard fragmentation case:
> > > 
> > >  page_range* range = nullptr;
> > >  if (!bitset) {
> > >  if (!exact_order || _free[exact_order - 1].empty()) {
> > > +printf("page_range_allocator: no ranges found for
> > size
> > > %ld and exact order: %d\n", size, exact_order);
> > >  return nullptr;
> > >  }
> > > 
> > > On Saturday, March 21, 2020 at 7:17:16 PM UTC-4, rickp wrote:
> > > > Ok, with the waiter_print, we see: 
> > > > 
> > > > Waiter: 2_scheduler, bytes: 4984832 
> > > > Waiter: 5_scheduler, bytes: 4984832 
> > > > Out of memory: could not reclaim any further. Current memory: 
> > > > 10871576Kb, target: 0 Kb 
> > > > 
> > > > 'osv mem' in gdb reports loads of free memory: 
> > > > 
> > > > (gdb) osv mem 
> > > > Total Memory: 12884372480 Bytes 
> > > > Mmap Memory:  1610067968 Bytes (12.50%) 
> > > > Free Memory:  11132493824 Bytes (86.40%) 
> > > > 
> > > > So why is it failing to allocate 5MB when it claims to have
> > 11GB
> > > > free? 
> > > > 
> > > > Any more debug I can provide? 
> > > > 
> > > > Rick 
> > > > 
> > > > On Sat, 2020-03-21 at 15:32 +1000, Rick Payne wrote: 
> > > > > And indeed, back on the 'release' image, and we hit an oom: 
> > > > > 
> > > > > (gdb) b memory::oom 
> > > > > Breakpoint 1 at 0x403ee300: file core/mempool.cc, line 505. 
> > > > > (gdb) c 
> > > > > Continuing. 
> > > > > 
> > > > > Thread 1 hit Breakpoint 1, memory::oom (target=target@entry=0
> > )
> > > > at 
> > > > > core/mempool.cc:505 
> > > > > 505 core/mempool.cc: No such file or directory. 
> > > > > (gdb) osv memory 
> > > > > Total Memory: 12884372480 Bytes 
> > > > > Mmap Memory:  1541332992 Bytes (11.96%) 
> > > > > Free Memory:  11490983936 Bytes (89.19%) 
> > > > > 
> > > > > I don't have the _waiters list print unforutnately (as I
> > hadn't 
> > > > > included it in this image). It looks like this though: 
> > > > > 
> > > > > (gdb) p _oom_blocked._waiters 
> > > > > $4 = 
> > > > >
> > > >
> > { > > > cl 
> > > > > ai 
> > > > > mer_waiters::wait_node,
> > > > boost::intrusive::list_node_traits, 
> > > > > (boost::intrusive::link_mode_type)1,
> > boost::intrusive::dft_tag,
> > > > 1>, 
> > > > > unsigned long, false, void>> = {static constant_time_size =
> > > > false, 
> > > > > static stateful_value_traits = , 
> > > > > static has_container_from_iterator = ,
> > static 
> > > > > safemode_or_autounlink = true, 
> > > > > data_ = 
> > > > >
> > > >
> > { > > > > boost::intrusive::list_node_traits, 
> > > > > (boost::intrusive::link_mode_type)1,
> > boost::intrusive::dft_tag,
> > > > 1>> = 
> > > > >
> > > >
> > { > > > od 
> > > > > e, 
> > > > > boost::intrusive::list_node*,
> > boost::intrusive::dft_tag,
> > > > 1>> = 
> > > > > {}, static link_mode =
> > > > boost::intrusive::safe_link}, 
> > > > >   root_plus_size_ = 
> > > > > { > > > > unsigned long, void>> = { 
> > > > >   static constant_time_size = },
> > m_header
> > > > = 
> > > > > {> = { 
> > > > > next_ = 0x200041305580, prev_ = 0x200041305580},
> >  > > 

Re: [osv-dev] Re: OOM query

2020-03-22 Thread Waldek Kozaczuk
Can you run ‘osv heap’ from gdb at this point?

On Sun, Mar 22, 2020 at 19:31 Rick Payne  wrote:

>
> Ok, so i applied the patch, and the printf and this is what I see:
>
> page_range_allocator: no ranges found for size 39849984 and exact
> order: 14
> Waiter: 1_scheduler, bytes: 39849984
> Out of memory: could not reclaim any further. Current memory: 10933128
> Kb, target: 0 Kb
>
> Rick
>
> On Sat, 2020-03-21 at 21:16 -0700, Waldek Kozaczuk wrote:
> >
> >
> > I think that OSv might be hitting some sort of fragmentation scenario
> > (another question is why we get to this point) which should be
> > handled but is not due to the bug this patch fixes:
> >
> > diff --git a/core/mempool.cc b/core/mempool.cc
> > index d902eea8..11fd1456 100644
> > --- a/core/mempool.cc
> > +++ b/core/mempool.cc
> > @@ -702,10 +702,13 @@ page_range* page_range_allocator::alloc(size_t
> > size)
> >  for (auto&& pr : _free[exact_order - 1]) {
> >  if (pr.size >= size) {
> >  range = 
> > +remove_list(exact_order - 1, *range);
> >  break;
> >  }
> >  }
> > -return nullptr;
> > +if (!range) {
> > +return nullptr;
> > +}
> >  } else if (order == max_order) {
> >  range = &*_free_huge.rbegin();
> >  if (range->size < size) {
> >
> > Can you give it a try and see what happens with this patch?
> >
> > Waldek
> >
> > PS. You might also add this printout to verify if you are hitting the
> > hard fragmentation case:
> >
> >  page_range* range = nullptr;
> >  if (!bitset) {
> >  if (!exact_order || _free[exact_order - 1].empty()) {
> > +printf("page_range_allocator: no ranges found for size
> > %ld and exact order: %d\n", size, exact_order);
> >  return nullptr;
> >  }
> >
> > On Saturday, March 21, 2020 at 7:17:16 PM UTC-4, rickp wrote:
> > > Ok, with the waiter_print, we see:
> > >
> > > Waiter: 2_scheduler, bytes: 4984832
> > > Waiter: 5_scheduler, bytes: 4984832
> > > Out of memory: could not reclaim any further. Current memory:
> > > 10871576Kb, target: 0 Kb
> > >
> > > 'osv mem' in gdb reports loads of free memory:
> > >
> > > (gdb) osv mem
> > > Total Memory: 12884372480 Bytes
> > > Mmap Memory:  1610067968 Bytes (12.50%)
> > > Free Memory:  11132493824 Bytes (86.40%)
> > >
> > > So why is it failing to allocate 5MB when it claims to have 11GB
> > > free?
> > >
> > > Any more debug I can provide?
> > >
> > > Rick
> > >
> > > On Sat, 2020-03-21 at 15:32 +1000, Rick Payne wrote:
> > > > And indeed, back on the 'release' image, and we hit an oom:
> > > >
> > > > (gdb) b memory::oom
> > > > Breakpoint 1 at 0x403ee300: file core/mempool.cc, line 505.
> > > > (gdb) c
> > > > Continuing.
> > > >
> > > > Thread 1 hit Breakpoint 1, memory::oom (target=target@entry=0)
> > > at
> > > > core/mempool.cc:505
> > > > 505 core/mempool.cc: No such file or directory.
> > > > (gdb) osv memory
> > > > Total Memory: 12884372480 Bytes
> > > > Mmap Memory:  1541332992 Bytes (11.96%)
> > > > Free Memory:  11490983936 Bytes (89.19%)
> > > >
> > > > I don't have the _waiters list print unforutnately (as I hadn't
> > > > included it in this image). It looks like this though:
> > > >
> > > > (gdb) p _oom_blocked._waiters
> > > > $4 =
> > > >
> > > { > > cl
> > > > ai
> > > > mer_waiters::wait_node,
> > > boost::intrusive::list_node_traits,
> > > > (boost::intrusive::link_mode_type)1, boost::intrusive::dft_tag,
> > > 1>,
> > > > unsigned long, false, void>> = {static constant_time_size =
> > > false,
> > > > static stateful_value_traits = ,
> > > > static has_container_from_iterator = , static
> > > > safemode_or_autounlink = true,
> > > > data_ =
> > > >
> > > { > > > boost::intrusive::list_node_traits,
> > > > (boost::intrusive::link_mode_type)1, boost::intrusive::dft_tag,
> > > 1>> =
> > > >
> > > { > > od
> > > > e,
> > > > boost::intrusive::list_node*, boost::intrusive::dft_tag,
> > > 1>> =
> > > > {}, static link_mode =
> > > boost::intrusive::safe_link},
> > > >   root_plus_size_ =
> > > > { > > > unsigned long, void>> = {
> > > >   static constant_time_size = }, m_header
> > > =
> > > > {> = {
> > > > next_ = 0x200041305580, prev_ = 0x200041305580},  > > data
> > > > fields>, }
> > > >
> > > > 'osv waiters' fails, annoyingly:
> > > >
> > > > (gdb) osv waiters
> > > > waiters:
> > > > Python Exception  Cannot access memory
> > > at
> > > > address 0x42c00020982ac010:
> > > > Error occurred in Python command: Cannot access memory at
> > > address
> > > > 0x42c00020982ac010
> > > >
> > > > Rick
> > > >
> > > > On Sat, 2020-03-21 at 06:42 +1000, Rick Payne wrote:
> > > > > So we've been trying with a debug image (with the tcp kassert
> > > > > disabled). We do not get an OOM crash, but after some time
> > > (24hrs
> > > > > or
> > > > > more) all cores just hit idle and never recover. It stops
> > > > > responding
> > > > > to
> 

Re: [osv-dev] Re: OOM query

2020-03-22 Thread Rick Payne


Ok, so i applied the patch, and the printf and this is what I see:

page_range_allocator: no ranges found for size 39849984 and exact
order: 14
Waiter: 1_scheduler, bytes: 39849984
Out of memory: could not reclaim any further. Current memory: 10933128
Kb, target: 0 Kb

Rick

On Sat, 2020-03-21 at 21:16 -0700, Waldek Kozaczuk wrote:
> 
> 
> I think that OSv might be hitting some sort of fragmentation scenario
> (another question is why we get to this point) which should be
> handled but is not due to the bug this patch fixes:
> 
> diff --git a/core/mempool.cc b/core/mempool.cc
> index d902eea8..11fd1456 100644
> --- a/core/mempool.cc
> +++ b/core/mempool.cc
> @@ -702,10 +702,13 @@ page_range* page_range_allocator::alloc(size_t
> size)
>  for (auto&& pr : _free[exact_order - 1]) {
>  if (pr.size >= size) {
>  range = 
> +remove_list(exact_order - 1, *range);
>  break;
>  }
>  }
> -return nullptr;
> +if (!range) {
> +return nullptr;
> +}
>  } else if (order == max_order) {
>  range = &*_free_huge.rbegin();
>  if (range->size < size) {
> 
> Can you give it a try and see what happens with this patch?
> 
> Waldek
> 
> PS. You might also add this printout to verify if you are hitting the
> hard fragmentation case:
> 
>  page_range* range = nullptr;
>  if (!bitset) {
>  if (!exact_order || _free[exact_order - 1].empty()) {
> +printf("page_range_allocator: no ranges found for size
> %ld and exact order: %d\n", size, exact_order);
>  return nullptr;
>  }
> 
> On Saturday, March 21, 2020 at 7:17:16 PM UTC-4, rickp wrote:
> > Ok, with the waiter_print, we see: 
> > 
> > Waiter: 2_scheduler, bytes: 4984832 
> > Waiter: 5_scheduler, bytes: 4984832 
> > Out of memory: could not reclaim any further. Current memory: 
> > 10871576Kb, target: 0 Kb 
> > 
> > 'osv mem' in gdb reports loads of free memory: 
> > 
> > (gdb) osv mem 
> > Total Memory: 12884372480 Bytes 
> > Mmap Memory:  1610067968 Bytes (12.50%) 
> > Free Memory:  11132493824 Bytes (86.40%) 
> > 
> > So why is it failing to allocate 5MB when it claims to have 11GB
> > free? 
> > 
> > Any more debug I can provide? 
> > 
> > Rick 
> > 
> > On Sat, 2020-03-21 at 15:32 +1000, Rick Payne wrote: 
> > > And indeed, back on the 'release' image, and we hit an oom: 
> > > 
> > > (gdb) b memory::oom 
> > > Breakpoint 1 at 0x403ee300: file core/mempool.cc, line 505. 
> > > (gdb) c 
> > > Continuing. 
> > > 
> > > Thread 1 hit Breakpoint 1, memory::oom (target=target@entry=0)
> > at 
> > > core/mempool.cc:505 
> > > 505 core/mempool.cc: No such file or directory. 
> > > (gdb) osv memory 
> > > Total Memory: 12884372480 Bytes 
> > > Mmap Memory:  1541332992 Bytes (11.96%) 
> > > Free Memory:  11490983936 Bytes (89.19%) 
> > > 
> > > I don't have the _waiters list print unforutnately (as I hadn't 
> > > included it in this image). It looks like this though: 
> > > 
> > > (gdb) p _oom_blocked._waiters 
> > > $4 = 
> > >
> > { > cl 
> > > ai 
> > > mer_waiters::wait_node,
> > boost::intrusive::list_node_traits, 
> > > (boost::intrusive::link_mode_type)1, boost::intrusive::dft_tag,
> > 1>, 
> > > unsigned long, false, void>> = {static constant_time_size =
> > false, 
> > > static stateful_value_traits = , 
> > > static has_container_from_iterator = , static 
> > > safemode_or_autounlink = true, 
> > > data_ = 
> > >
> > { > > boost::intrusive::list_node_traits, 
> > > (boost::intrusive::link_mode_type)1, boost::intrusive::dft_tag,
> > 1>> = 
> > >
> > { > od 
> > > e, 
> > > boost::intrusive::list_node*, boost::intrusive::dft_tag,
> > 1>> = 
> > > {}, static link_mode =
> > boost::intrusive::safe_link}, 
> > >   root_plus_size_ = 
> > > { > > unsigned long, void>> = { 
> > >   static constant_time_size = }, m_header
> > = 
> > > {> = { 
> > > next_ = 0x200041305580, prev_ = 0x200041305580},  > data 
> > > fields>, } 
> > > 
> > > 'osv waiters' fails, annoyingly: 
> > > 
> > > (gdb) osv waiters 
> > > waiters: 
> > > Python Exception  Cannot access memory
> > at 
> > > address 0x42c00020982ac010: 
> > > Error occurred in Python command: Cannot access memory at
> > address 
> > > 0x42c00020982ac010 
> > > 
> > > Rick 
> > > 
> > > On Sat, 2020-03-21 at 06:42 +1000, Rick Payne wrote: 
> > > > So we've been trying with a debug image (with the tcp kassert 
> > > > disabled). We do not get an OOM crash, but after some time
> > (24hrs 
> > > > or 
> > > > more) all cores just hit idle and never recover. It stops 
> > > > responding 
> > > > to 
> > > > TCP connections and when you attached gdb, you see this: 
> > > > 
> > > > Thread 1 received signal SIGINT, Interrupt. 
> > > > processor::sti_hlt () at arch/x64/processor.hh:252 
> > > > 252 arch/x64/processor.hh: No such file or directory. 
> > > > (gdb) info thread 
> > > >   Id   Target Id 

[osv-dev] [PATCH 2/2] tests: move nfs testing out to a separate module

2020-03-22 Thread Waldemar Kozaczuk
This patch moves nfs testing logic from ./scripts/test.py
into ./modules/nfs-tests/test.py.

It also refreshes nfs-tests to pull and build UNFS3 (NFS in user space)
from a new repo. Eventually it adds new 'check' target
that builds the test image (nfs,nfs-tests) and runs test.py against it.

Signed-off-by: Waldemar Kozaczuk 
---
 modules/nfs-tests/.gitignore |  4 ++
 modules/nfs-tests/Makefile   | 32 +
 modules/nfs-tests/test.py| 90 
 modules/nfs-tests/tst-nfs.cc | 64 ++---
 scripts/test.py  | 62 ++---
 5 files changed, 157 insertions(+), 95 deletions(-)
 create mode 100644 modules/nfs-tests/.gitignore
 create mode 100755 modules/nfs-tests/test.py

diff --git a/modules/nfs-tests/.gitignore b/modules/nfs-tests/.gitignore
new file mode 100644
index ..a2666565
--- /dev/null
+++ b/modules/nfs-tests/.gitignore
@@ -0,0 +1,4 @@
+*.so
+*.d
+unfsd.bin
+upstream
diff --git a/modules/nfs-tests/Makefile b/modules/nfs-tests/Makefile
index 852df8bd..86379e81 100644
--- a/modules/nfs-tests/Makefile
+++ b/modules/nfs-tests/Makefile
@@ -1,17 +1,18 @@
 quiet = $(if $V, $1, @echo " $2"; $1)
 
-UNFS_URL="https://github.com/benoit-canet/unfsd.git;
+UNFS_URL="https://github.com/unfs3/unfs3.git;
 
 autodepend = -MD -MT $@ -MP
 
-src := $(OSV_BASE)
-out := $(OSV_BUILD_PATH)
+src = $(shell readlink -f ../..)
 arch := $(ARCH)
 
-INCLUDES = -I$(src)/arch/$(ARCH) -I$(src) -I$(src)/include \
-   -I$(src)/arch/common -isystem $(src)/include/glibc-compat \
-   -isystem $(src)/include/api -isystem $(src)/include/api/$(ARCH) \
-   -isystem $(out)/gen/include
+INCLUDES = -I../../include
+INCLUDES += -I../../arch/$(ARCH) -I../.. -I../../build/$(mode)/gen/include
+INCLUDES += -isystem ../../include/glibc-compat
+INCLUDES += $(shell $(CXX) -E -xc++ - -v &1 | awk '/^End/ {exit} 
/^ .*c\+\+/ {print "-isystem" $$0}')
+INCLUDES += -isystem ../../include/api -isystem ../../include/api/$(ARCH) 
-isystem ../../build/$(mode)/gen/include
+INCLUDES += -isystem ../../bsd/sys -isystem ../../bsd/ -isystem 
../../bsd/$(ARCH)
 
 CORE = $(autodepend) $(INCLUDES) -g -O2 -fPIC
 COMMON = $(CORE) -DBOOST_TEST_DYN_LINK \
@@ -24,14 +25,25 @@ CFLAGS = -std=gnu99 $(COMMON)
 module: unfsd.bin tst-nfs fsx-linux
 
 unfsd.bin:
-   $(call quiet, git clone $(UNFS_URL)) && \
-   $(call quiet, cd unfsd) && \
+   $(call quiet, mkdir -p upstream) && \
+   $(call quiet, git clone $(UNFS_URL) upstream/unfs3) && \
+   $(call quiet, cd upstream/unfs3) && \
+   $(call quiet, ./bootstrap) && \
$(call quiet, ./configure) && \
$(call quiet, make)
-   $(call quiet, cp unfsd/unfsd unfsd.bin)
+   $(call quiet, cp upstream/unfs3/unfsd unfsd.bin)
 
 tst-nfs:
$(call quiet, $(CXX) $(CXXFLAGS) -shared -o tst-nfs.so tst-nfs.cc, LINK 
$@)
 
 fsx-linux:
$(call quiet, $(CC)  $(CORE) -shared -o fsx-linux.so fsx-linux.c, LINK 
$@)
+
+check:
+   cd $(src) && \
+   make image=nfs,nfs-tests && \
+   PYTHONPATH=$(src)/scripts modules/nfs-tests/test.py
+
+clean:
+   $(call quiet, rm -rf upstream, RM upstream)
+   $(call quiet, rm -f *.so unfsd.bin *.d, RM *.so)
diff --git a/modules/nfs-tests/test.py b/modules/nfs-tests/test.py
new file mode 100755
index ..b4797bf6
--- /dev/null
+++ b/modules/nfs-tests/test.py
@@ -0,0 +1,90 @@
+#!/usr/bin/env python3
+
+import time
+import tempfile
+import atexit
+from tests.testing import *
+
+def make_export_and_conf():
+export_dir = tempfile.mkdtemp(prefix='share')
+os.chmod(export_dir, 0o777)
+(conf_fd, conf_path) = tempfile.mkstemp(prefix='export')
+conf = os.fdopen(conf_fd, "w")
+conf.write("%s 127.0.0.1(insecure,rw)\n" % export_dir)
+conf.flush()
+conf.close()
+return (conf_path, export_dir)
+
+proc = None
+conf_path = None
+export_dir = None
+
+def kill_unfsd():
+global proc, conf_path, export_dir
+proc.kill()
+proc.wait()
+if conf_path and os.path.exists(conf_path):
+os.unlink(conf_path)
+if export_dir and os.path.exists(export_dir):
+import shutil
+shutil.rmtree(export_dir, ignore_errors=True)
+
+dirname = os.path.dirname(os.path.abspath(__file__))
+UNFSD = dirname + "/unfsd.bin"
+
+def run_test():
+global proc, conf_path, export_dir
+start = time.time()
+
+if not os.path.exists(UNFSD):
+print("Please do:\n\tmake nfs-server")
+sys.exit(1)
+
+(conf_path, export_dir) = make_export_and_conf()
+
+ret = subprocess.call(['rpcinfo'])
+if ret != 0:
+print('Please install rpcbind!')
+exit(-1)
+
+proc = subprocess.Popen([os.path.join(os.getcwd(), UNFSD),
+ "-t",
+ "-d",
+ "-s",
+ "-l", "127.0.0.1",
+ "-e", conf_path ],
+ stdin = sys.stdin,
+   

[osv-dev] [PATCH 1/2] fs: move nfs support out of kernel in lieu of a separate pluggable module

2020-03-22 Thread Waldemar Kozaczuk
This patch removes external/fs/libnfs module and makes nfs support pluggable
by moving it into a module (shared library) that can be added to the image
instead of being compiled into the kernel using nfs=true build option.
The nfs support can be added by adding nfs module to the image.

More specifically:
- external/fs/libnfs is removed and equivalent modules/libnfs gets created
- most fs/nfs code except for fs_null_vfsops.cc gets moved out of a kernel
  into new modules/nfs that is built as a shared library
- vfs mount logic is able to dynamically load extra filesystem
  libraries from /usr/lib/fs

Completes #1078

Signed-off-by: Waldemar Kozaczuk 
---
 .gitmodules   |  3 --
 Makefile  | 32 ++--
 external/fs/libnfs|  1 -
 fs/nfs/nfs_null_vfsops.cc | 11 +-
 fs/vfs/main.cc| 17 +
 fs/vfs/vfs_conf.cc|  2 +-
 modules/libnfs/.gitignore |  1 +
 modules/libnfs/Makefile   | 19 ++
 modules/libnfs/usr.manifest   |  9 +
 modules/nfs/.gitignore|  3 ++
 modules/nfs/Makefile  | 46 +++
 modules/nfs/module.py |  3 ++
 {fs => modules}/nfs/nfs.cc|  2 +-
 {fs => modules}/nfs/nfs.hh|  2 +-
 {fs => modules}/nfs/nfs_vfsops.cc | 24 ++--
 {fs => modules}/nfs/nfs_vnops.cc  |  0
 tools/mount/{mount-nfs.cc => mount-fs.cc} | 13 +--
 usr.manifest.skel |  2 +-
 usr_ramfs.manifest.skel   |  2 +-
 usr_rofs.manifest.skel|  2 +-
 20 files changed, 139 insertions(+), 55 deletions(-)
 delete mode 16 external/fs/libnfs
 create mode 100644 modules/libnfs/.gitignore
 create mode 100644 modules/libnfs/Makefile
 create mode 100644 modules/libnfs/usr.manifest
 create mode 100644 modules/nfs/.gitignore
 create mode 100644 modules/nfs/Makefile
 create mode 100644 modules/nfs/module.py
 rename {fs => modules}/nfs/nfs.cc (97%)
 rename {fs => modules}/nfs/nfs.hh (96%)
 rename {fs => modules}/nfs/nfs_vfsops.cc (74%)
 rename {fs => modules}/nfs/nfs_vnops.cc (100%)
 rename tools/mount/{mount-nfs.cc => mount-fs.cc} (70%)

diff --git a/.gitmodules b/.gitmodules
index b6ae6ac1..17a2c18e 100644
--- a/.gitmodules
+++ b/.gitmodules
@@ -15,6 +15,3 @@
 [submodule "modules/httpserver/osv-gui"]
path = modules/httpserver-html5-gui/osv-gui
url = ../../cloudius-systems/osv-gui.git
-[submodule "external/fs/libnfs"]
-   path = external/fs/libnfs
-   url = https://github.com/sahlberg/libnfs.git
diff --git a/Makefile b/Makefile
index 03a17920..9401e809 100644
--- a/Makefile
+++ b/Makefile
@@ -4,8 +4,6 @@
 # This work is open source software, licensed under the terms of the
 # BSD license as described in the LICENSE file in the top-level directory.
 
-# The nfs=true flag will build in the NFS client filesystem support
-
 # Delete the builtin make rules, as if "make -r" was used.
 .SUFFIXES:
 
@@ -142,25 +140,10 @@ check:
./scripts/build check
 .PHONY: check
 
-libnfs-path = external/fs/libnfs/
-
-$(out)/libnfs.a:
-   cd $(libnfs-path) && \
-   $(call quiet, ./bootstrap) && \
-   $(call quiet, ./configure --enable-shared=no --enable-static=yes 
--enable-silent-rules) && \
-   $(call quiet, make)
-   $(call quiet, cp -a $(libnfs-path)/lib/.libs/libnfs.a $(out)/libnfs.a)
-
-clean-libnfs:
-   if [ -f $(out)/libnfs.a ] ; then \
-   cd $(libnfs-path) && \
-   make distclean; \
-   fi
-
 # Remember that "make clean" needs the same parameters that set $(out) in
 # the first place, so to clean the output of "make mode=debug" you need to
 # do "make mode=debug clean".
-clean: clean-libnfs
+clean:
rm -rf $(out)
rm -f $(outlink) $(outlink2)
 .PHONY: clean
@@ -374,7 +357,7 @@ tools += tools/uush/uush.so
 tools += tools/uush/ls.so
 tools += tools/uush/mkdir.so
 
-tools += tools/mount/mount-nfs.so
+tools += tools/mount/mount-fs.so
 tools += tools/mount/umount.so
 
 ifeq ($(arch),aarch64)
@@ -1849,14 +1832,7 @@ endif
 
 boost-libs := $(boost-lib-dir)/libboost_system$(boost-mt).a
 
-ifeq ($(nfs), true)
-   nfs-lib = $(out)/libnfs.a
-   nfs_o = nfs.o nfs_vfsops.o nfs_vnops.o
-else
-   nfs_o = nfs_null_vfsops.o
-endif
-
-objects += $(addprefix fs/nfs/, $(nfs_o))
+objects += fs/nfs/nfs_null_vfsops.o
 
 # ld has a known bug (https://sourceware.org/bugzilla/show_bug.cgi?id=6468)
 # where if the executable doesn't use shared libraries, its .dynamic section
@@ -1865,7 +1841,7 @@ objects += $(addprefix fs/nfs/, $(nfs_o))
 $(out)/dummy-shlib.so: $(out)/dummy-shlib.o
$(call quiet, $(CXX) -nodefaultlibs -shared $(gcc-sysroot) -o $@ $^, 
LINK $@)
 
-stage1_targets = $(out)/arch/$(arch)/boot.o $(out)/loader.o $(out)/runtime.o 
$(drivers:%=$(out)/%) $(objects:%=$(out)/%)