Re: [BUG ?] Offline Memory gets stuck in offline_pages()

["Zhijian Li (Fujitsu)" <lizhijian@fujitsu.com>]

David && ALL,

Some progress updates

On 04/07/2024 21:07, Zhijian Li (Fujitsu) wrote:
> 
> 
>> -----Original Message-----
>> From: David Hildenbrand <david@redhat.com>
>> Sent: Thursday, July 4, 2024 4:15 PM
> 
> 
>>
>> On 04.07.24 09:43, Zhijian Li (Fujitsu) wrote:
>>> All,
>>>
>>> Some progress updates
>>>
>>> When issue occurs, calling __drain_all_pages() can make offline_pages() escape
>> from the loop.
>>>
>>>>
>>>> Jun 28 15:29:26 linux kernel: page: refcount:0 mapcount:0
>>>> mapping:0000000000000000 index:0x0 pfn:0x7980dd Jun 28 15:29:26 linux
>>>> kernel: flags: 0x9fffffc0000000(node=2|zone=3|lastcpupid=0x1fffff)
>>>> Jun 28 15:29:26 linux kernel: raw: 009fffffc0000000 ffffdfbd9e603788
>>>> ffffd4f0ffd97ef0 0000000000000000 Jun 28 15:29:26 linux kernel: raw:
>>>> 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
>> Jun 28 15:29:26 linux kernel: page dumped because: trouble page...
>>>>
>>>
>>> With this problematic page structure contents, it seems that the
>>> list_head = {ffffdfbd9e603788, ffffd4f0ffd97ef0} is valid.
>>>
>>> I guess it was linking to the pcp_list, so I dumped the
>>> per_cpu_pages[cpu].count in every in critical timings.
>>
>> So, is your reproducer getting fixed when you call __drain_all_pages() in the loop?
>> (not that it's the right fix, but a could datapoint :) )
> 
> Yeah,  it works for my reproducer.
> 
> 
> 
>>
>>>
>>> An example is as below,
>>> offline_pages()
>>> {
>>> 	// per_cpu_pages[1].count = 0
>>> 	zone_pcp_disable() // will call __drain_all_pages()
>>> 	// per_cpu_pages[1].count = 188
>>> 	do {
>>> 		do {
>>> 			scan_movable_pages()
>>> 			ret = do_migrate_range()
>>> 		} while (!ret)
>>>
>>> 		ret = test_pages_isolated()
>>>
>>> 		if(is the 1st iteration)
>>> 			// per_cpu_pages[1].count = 182
>>>
>>> 		if (issue occurs) { /* if the loop take beyond 10 seconds */
>>> 			// per_cpu_pages[1].count = 61
>>> 			__drain_all_pages()
>>> 			// per_cpu_pages[1].count = 0
>>> 			/* will escape from the outer loop in later iterations */
>>> 		}
>>> 	} while (ret)
>>> }
>>>
>>> Some interesting points:
>>>     - After the 1st __drain_all_pages(), per_cpu_pages[1].count increased to 188
>> from 0,
>>>       does it mean it's racing with something...?
>>>     - per_cpu_pages[1].count will decrease but not decrease to 0 during
>> iterations
>>>     - when issue occurs, calling __drain_all_pages() will decrease
>> per_cpu_pages[1].count to 0.
>>
>> That's indeed weird. Maybe there is a race, or zone_pcp_disable() is not fully
>> effective for a zone?
> 
> I often see there still are pages in PCP after the zone_pcp_disable().
> 
>>
>>>
>>> So I wonder if it's fine to call __drain_all_pages() in the loop?
>>>
>>> Looking forward to your insights.
>>
>> So, in free_unref_page(), we make sure to never place MIGRATE_ISOLATE onto
>> the PCP. All pageblocks we are going to offline should be isolated at this point, so
>> no page that is getting freed and part of the to-be-offlined range should end up on
>> the PCP. So far the theory.
>>
>>
>> In offlining code we do
>>
>> 1) Set MIGRATE_ISOLATE
>> 2) zone_pcp_disable() -> set high-and-batch to 0  and drain
>>
>> Could there be a race in free_unref_page(), such that although
>> zone_pcp_disable() succeeds, we would still end up with a page in the pcp?
>> (especially, one that has MIGRATE_ISOLATE set for its pageblock?)
> 
> Thanks for your idea, I will further investigate in this direction.

some updates


         CPU0                                  CPU1
     -----------                           ---------
// erase pcp_list
zone_pcp_disable // pcp->count = 0
                                                                                       
lru_cache_diable()                    __rmqueue_pcplist()  // re-add pages to pcp_lsit
                                       __rmqueue_pcplist()  // drop pages from pcp_list
                                       decay_pcp_high()     // drop pages from pcp_list
loop  {                                      ...
                                       __rmqueue_pcplist()  // drop pages from pcp_list,
                                                            // it will be only called a few times during the loop
      scan_movable_pages()                   ...
      migration_pages()                decay_pcp_high()     // drop pages from pcp_list, it will be called by
                                                            // a worker periodically during the loop
                                                                                       
// wait pcp_list to be empty
} while (test_pages_isolated())


And we noticed that re-add pages to pcp_list in '__rmqueue_pcplist()` only happen once,
pcp->count changed to 200 from 0 for example.

The later calls to __rmqueue_pcplist() will drop pcp->count by step 1 for each call,
For example, pcp->count: 199->198->197->196...,
However it stops calling __rmqueue_pcplist after a few times before pcp->count is dropped to 0.

In the normal/good case, we also noticed that __rmqueue_pcplist() dropped pcp->count to 0.


Here is the __rmqueue_pcplist() call trace.
CPU: 1 PID: 3615 Comm: consume_std_pag Not tainted 6.10.0-rc2+ #147
Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014
Call Trace:
  <TASK>
  dump_stack_lvl+0x64/0x80
  __rmqueue_pcplist+0xd55/0xdf0
  get_page_from_freelist+0x2a1/0x1770
  __alloc_pages_noprof+0x1a0/0x380
  alloc_pages_mpol_noprof+0xe3/0x1f0
  vma_alloc_folio_noprof+0x5c/0xb0
  folio_prealloc+0x21/0x80
  do_pte_missing+0x695/0xa20
  ? __pte_offset_map+0x1b/0x180
  __handle_mm_fault+0x65f/0xc10
  ? kmem_cache_free+0x370/0x410
  handle_mm_fault+0x128/0x360
  do_user_addr_fault+0x309/0x810
  exc_page_fault+0x7e/0x180
  asm_exc_page_fault+0x26/0x30
RIP: 0033:0x7f3d8729028a


In the meantime, decay_pcp_high() will be called to drop the pcp->count periodically.
[  145.117256]  decay_pcp_high+0x68/0x90
[  145.117256]  refresh_cpu_vm_stats+0x149/0x2a0
[  145.117256]  vmstat_update+0x13/0x50
[  145.117256]  process_scheduled_works+0xa6/0x420
[  145.117256]  worker_thread+0x117/0x270
[  145.117256]  ? __pfx_worker_thread+0x10/0x10
[  145.117256]  kthread+0xe5/0x120
[  145.117256]  ? __pfx_kthread+0x10/0x10
[  145.117256]  ret_from_fork+0x34/0x40
[  145.117256]  ? __pfx_kthread+0x10/0x10
[  145.117256]  ret_from_fork_asm+0x1a/0x30

But decay_pcp_high() will stop dropping pcp->count after a few moment later. IOW
decay_pcp_high() will be called periodically though, it doesn't drop pcp->count.
A piece of pcp content shows as below:
...
   count = 7,
   high = 7,
   high_min = 0,
   high_max = 0,
   batch = 1,
   flags = 0 '\000',
   alloc_factor = 3 '\003',
   expire = 0 '\000',
   free_count = 0,
   lists = {{
...

2244  * Called from the vmstat counter updater to decay the PCP high.
2245  * Return whether there are addition works to do.
2246  */
2247 int decay_pcp_high(struct zone *zone, struct per_cpu_pages *pcp)
2248 {
2249         int high_min, to_drain, batch;
2250         int todo = 0;
2251
2252         high_min = READ_ONCE(pcp->high_min);
2253         batch = READ_ONCE(pcp->batch);
2254         /*
2255          * Decrease pcp->high periodically to try to free possible
2256          * idle PCP pages.  And, avoid to free too many pages to
2257          * control latency.  This caps pcp->high decrement too.
2258          */
2259         if (pcp->high > high_min) {
2260                 pcp->high = max3(pcp->count - (batch << CONFIG_PCP_BATCH_SCALE_MAX),
2261                                  pcp->high - (pcp->high >> 3), high_min);
2262                 if (pcp->high > high_min)
2263                         todo++;
2264         }
2265
2266         to_drain = pcp->count - pcp->high;    // to_drain will be 0(when count == high),
                                                    // so no any pages can be drop from pcp_list.
2267         if (to_drain > 0) {
2268                 spin_lock(&pcp->lock);
2269                 free_pcppages_bulk(zone, to_drain, pcp, 0);
2270                 spin_unlock(&pcp->lock);
2271                 todo++;
2272         }
2273
2274         if (mutex_is_locked(&pcp_batch_high_lock) && pcp->high_max == 0 && to_drain > 0 && pcp->count >= 0)
2275                 pr_info("lizhijian:%s,%d: cpu%d, to_drain %d, new %d\n", __func__, __LINE__, smp_processor_id(), to_drain, pcp->count);
2277         return todo;
2278 }


I'm wondering if we can fix it in decay_pcp_high(), let it drop pcp->count to 0 when zone_pcp_disable()


The following logs show the pcp->count(*new* is pcp->count in the end of the function) in the bad case.
=====================

Jul 11 18:34:14 linux kernel: lizhijian:__rmqueue_pcplist,2945: cpu1, pfn 6a0159, old 71, new 70, add 0, drop 1
Jul 11 18:34:14 linux kernel: lizhijian:__rmqueue_pcplist,2945: cpu1, pfn 6a015a, old 70, new 69, add 0, drop 1
Jul 11 18:34:14 linux kernel: lizhijian:__rmqueue_pcplist,2945: cpu1, pfn 6a015b, old 69, new 68, add 0, drop 1
Jul 11 18:34:14 linux kernel: lizhijian:__rmqueue_pcplist,2945: cpu1, pfn 6a015c, old 68, new 67, add 0, drop 1
Jul 11 18:34:14 linux kernel: lizhijian:__rmqueue_pcplist,2945: cpu1, pfn 6a015d, old 67, new 66, add 0, drop 1
Jul 11 18:34:14 linux kernel: lizhijian:__rmqueue_pcplist,2945: cpu1, pfn 6a015e, old 66, new 65, add 0, drop 1
Jul 11 18:34:14 linux kernel: lizhijian:__rmqueue_pcplist,2945: cpu1, pfn 6a015f, old 65, new 64, add 0, drop 1
...
Jul 11 18:34:18 linux kernel: lizhijian: offline_pages,2087: cpu0: [6a0000-6a8000] get trouble: pcplist[1]: 0->63, batch 1, high 154
...

Jul 11 18:34:25 linux kernel: lizhijian:decay_pcp_high,2275: cpu1, to_drain 7, new 56
Jul 11 18:34:26 linux kernel: lizhijian:decay_pcp_high,2275: cpu1, to_drain 7, new 49
Jul 11 18:34:27 linux kernel: lizhijian:decay_pcp_high,2275: cpu1, to_drain 6, new 43
...
Jul 11 18:34:40 linux kernel: lizhijian:decay_pcp_high,2275: cpu1, to_drain 1, new 10
Jul 11 18:34:41 linux kernel: lizhijian:decay_pcp_high,2275: cpu1, to_drain 1, new 9
Jul 11 18:34:42 linux kernel: lizhijian:decay_pcp_high,2275: cpu1, to_drain 1, new 8
Jul 11 18:34:43 linux kernel: lizhijian:decay_pcp_high,2275: cpu1, to_drain 1, new 7
=====================

Thanks
Zhijian


> 
> 
> Thanks
> Zhijian
> 
>>
>>
>> --
>> Cheers,
>>
>> David / dhildenb
>