[CRIU] error in VDSO remap

[Pavel Emelyanov]

On 06/04/2015 03:31 PM, Tycho Andersen wrote:
> On Thu, Jun 04, 2015 at 12:33:33PM +0300, Pavel Emelyanov wrote:
>> On 06/04/2015 02:16 AM, Tycho Andersen wrote:
>>> Hi Pavel,
>>>
>>> On Tue, Jun 02, 2015 at 08:21:17AM +0300, Pavel Emelyanov wrote:
>>>> On 06/02/2015 06:39 AM, Tycho Andersen wrote:
>>>>> Hi all,
>>>>>
>>>>> When I try and c/r with current trunk, sometimes I get an error in the
>>>>> vdso remap code. The error message looks garbled (I am using current
>>>>> trunk), so I'm not sure what's really going on. Two examples are:
>>>>>
>>>>> http://paste.ubuntu.com/11510594/
>>>>> http://paste.ubuntu.com/11511094/
>>>>>
>>>>> This doesn't happen every time, but maybe 30% of the time.
>>>>>
>>>>> Any ideas?
>>>>
>>>> In the kernel code I can find only one reason for the EFAULT from
>>>> mremap -- the region we're trying to remap is not strictly included
>>>> into some single vma. IOW inside the (addr, addr + size) region
>>>> there should be either one whole vma or its part, but no two vmas
>>>> and no holes in the start or end of it.
>>>>
>>>> Can you stop (sleep 1000) the restoring task right after this message
>>>> and look inside its /proc/self/maps to compare what it remaps vs
>>>> what it really has?
>>>
>>> Here's the maps:
>>>
>>> http://paste.ubuntu.com/11552302/
>>>
>>> and here's my log:
>>>
>>> http://paste.ubuntu.com/11552304/
>>
>> Hm... It looks like these logs are succeeding:
>>
>> pie: vdso: Remap dumpee 0x26000 -> 0x7ffd61fdd000
>> pie: vdso: Remap dumpee 0x28000 -> 0x7ffd61fdf000
>> pie: Restoring scheduler params 0.0.0
>>
>>> It looks like it's trying to map something onto the end of the last
>>> region? 
>>
>> Well, yes. I have one idea of what can happen here. It looks like the 
>> VDSO CRIU sees in the image has managed to merge with some adjacent VMA
>> (because of the flags match) so we can't remap it into proper place because
>> of the sys_mremap limitations.
>>
>> Can you try to catch the failing case to see what CRIU remaps and what
>> mappings it has at that time?
> 
> Ah, sorry, the error is actually a bit above (search for "Error"); the
> sleep made it so that things didn't die right away :)

Yup, found it:

3179   pie: vdso: Remap rt-vvar 0x7fff95df9000 -> 0x26000
       pie: vdso: Remap rt-vdso 0x7fff95dfb000 -> 0x28000

and then

3266   pie: vdso: Runtime vdso/vvar matches dumpee, remap inplace
       pie: vdso: Remap dumpee 0x26000 -> 0x7ffd61fdd000
       pie: vdso: Remap dumpee 0x28000 -> 0x7ffd61fdf000
       pie: Error (arch/x86/vdso-pie.c:259): vdso: Unable to remap 0x28000 ->>
       pie:  0x7ffd61fdf000 0xfffffffffffffff2

Looking at the maps you provided there are

 4   00024000-00026000 rw-s 00000000 00:05 6128839                            /dev/zero (deleted)
     7f164a6e3000-7f164a6e7000 rwxp 00000000 fd:01 1343609                    /lib/x86_64-linux-gnu/libuuid.so.1.3.0
78   7ffd61fdd000-7ffd61fdf000 r--p 00000000 00:00 0                          [vvar]
     ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]

I.e. -- the 0x26000 address got remapped into 0x7ffd61fdd000 which happened to be vvar and
then the 0x28000 failed to get remapped for unknown reason. And what's bothering me is that
neither of addresses -- 0x28000 and 0x7ffd61fdf000 are present in the maps file.

But the first lines of loges I've shown mean that 0x28000 _must_ be there.

At the same time 3256 says:

pie: vdso: Parsing at 0x7ffd61fdf000 0x7ffd61fe1000

I.e. pie expects VDSO to be at the 0x7ffd61fdf000 address, while it should have already
being parked.

Cyrill, can you help us please :)

-- Pavel