On 01/24/2018 02:35 PM, Michal Hocko wrote: > On Wed 24-01-18 10:39:41, Anshuman Khandual wrote: >> On 01/23/2018 09:36 PM, Michal Hocko wrote: >>> On Tue 23-01-18 21:28:28, Anshuman Khandual wrote: >>>> On 01/23/2018 06:15 PM, Michal Hocko wrote: >>>>> On Tue 23-01-18 16:55:18, Anshuman Khandual wrote: >>>>>> On 01/17/2018 01:37 PM, Michal Hocko wrote: >>>>>>> On Thu 11-01-18 15:38:37, Anshuman Khandual wrote: >>>>>>>> On 01/09/2018 09:43 PM, Michal Hocko wrote: >>>>>>> [...] >>>>>>>>> Did you manage to catch _who_ is requesting that anonymous mapping? Do >>>>>>>>> you need a help with the debugging patch? >>>>>>>> Not yet, will get back on this. >>>>>>> ping? >>>>>> Hey Michal, >>>>>> >>>>>> Missed this thread, my apologies. This problem is happening only with >>>>>> certain binaries like 'sed', 'tmux', 'hostname', 'pkg-config' etc. As >>>>>> you had mentioned before the map request collision is happening on >>>>>> [10030000, 10040000] and [10030000, 10040000] ranges only which is >>>>>> just a single PAGE_SIZE. You asked previously that who might have >>>>>> requested the anon mapping which is already present in there ? Would >>>>>> not that be the same process itself ? I am bit confused. >>>>> We are early in the ELF loading. If we are mapping over an existing >>>>> mapping then we are effectivelly corrupting it. In other words exactly >>>>> what this patch tries to prevent. I fail to see what would be a relevant >>>>> anon mapping this early and why it would be colliding with elf >>>>> segements. >>>>> >>>>>> Would it be >>>>>> helpful to trap all the mmap() requests from any of the binaries >>>>>> and see where we might have created that anon mapping ? >>>>> Yeah, that is exactly what I was suggesting. Sorry for not being clear >>>>> about that. >>>>> >>>> Tried to instrument just for the 'sed' binary and dont see any where >>>> it actually requests the anon VMA which got hit when loading the ELF >>>> section which is strange. All these requested flags here already has >>>> MAP_FIXED_NOREPLACE (0x100000). Wondering from where the anon VMA >>>> actually came from. >>> Could you try to dump backtrace? >> This is when it fails inside elf_map() function due to collision with >> existing anon VMA mapping. > This is not the interesting one. This is the ELF loader. And we know it > fails. We are really interested in the one _who_ installs the original > VMA. Because nothing should be really there. > I tried to instrument mmap_region() for a single instance of 'sed' binary and traced all it's VMA creation. But there is no trace when that 'anon' VMA got created which suddenly shows up during subsequent elf_map() call eventually failing it. Please note that the following VMA was never created through call into map_region() in the process which is strange. ================================================================= [ 9.076867] Details for VMA[3] c000001fce42b7c0 [ 9.076925] vma c000001fce42b7c0 start 0000000010030000 end 0000000010040000 next c000001fce42b580 prev c000001fce42b880 mm c000001fce40fa00 prot 8000000000000104 anon_vma (null) vm_ops (null) pgoff 1003 file (null) private_data (null) flags: 0x100073(read|write|mayread|maywrite|mayexec|account) ================================================================= VMA creation for 'sed' binary ============================= [ 9.071902] XXX: mm c000001fce40fa00 registered [ 9.071971] Total VMAs 2 on MM c000001fce40fa00 ---- [ 9.072010] Details for VMA[1] c000001fce42bdc0 [ 9.072064] vma c000001fce42bdc0 start 0000000010000000 end 0000000010020000 next c000001fce42b580 prev (null) mm c000001fce40fa00 prot 8000000000000105 anon_vma (null) vm_ops c008000011ddca18 pgoff 0 file c000001fe2969a00 private_data (null) flags: 0x875(read|exec|mayread|maywrite|mayexec|denywrite) ---- [ 9.072402] Details for VMA[2] c000001fce42b580 [ 9.072469] vma c000001fce42b580 start 00007fffcafe0000 end 00007fffcb010000 next (null) prev c000001fce42bdc0 mm c000001fce40fa00 prot 8000000000000104 anon_vma c000001fce4456f0 vm_ops (null) pgoff 1fffffffd file (null) private_data (null) flags: 0x100173(read|write|mayread|maywrite|mayexec|growsdown|account) [ 9.072839] CPU: 48 PID: 7544 Comm: sed Not tainted 4.14.0-dirty #154 [ 9.072928] Call Trace: [ 9.072952] [c000001fbef37840] [c000000000b17a00] dump_stack+0xb0/0xf0 (unreliable) [ 9.073021] [c000001fbef37880] [c0000000002dbc48] mmap_region+0x718/0x720 [ 9.073097] [c000001fbef37970] [c0000000002dc034] do_mmap+0x3e4/0x480 [ 9.073179] [c000001fbef379f0] [c0000000002a96c8] vm_mmap_pgoff+0xe8/0x120 [ 9.073268] [c000001fbef37ac0] [c0000000003cf378] elf_map+0x98/0x270 [ 9.073326] [c000001fbef37b60] [c0000000003d1258] load_elf_binary+0x6f8/0x158c [ 9.073416] [c000001fbef37c80] [c00000000035d320] search_binary_handler+0xd0/0x270 [ 9.073510] [c000001fbef37d10] [c00000000035f278] do_execveat_common.isra.31+0x658/0x890 [ 9.073599] [c000001fbef37df0] [c00000000035f8c0] SyS_execve+0x40/0x50 [ 9.073673] [c000001fbef37e30] [c00000000000b220] system_call+0x58/0x6c [ 9.073749] Total VMAs 3 on MM c000001fce40fa00 ---- [ 9.073795] Details for VMA[1] c000001fce42bdc0 [ 9.073847] vma c000001fce42bdc0 start 0000000010000000 end 0000000010020000 next c000001fce42b880 prev (null) mm c000001fce40fa00 prot 8000000000000105 anon_vma (null) vm_ops c008000011ddca18 pgoff 0 file c000001fe2969a00 private_data (null) flags: 0x875(read|exec|mayread|maywrite|mayexec|denywrite) ---- [ 9.074170] Details for VMA[2] c000001fce42b880 [ 9.074236] vma c000001fce42b880 start 0000000010020000 end 0000000010030000 next c000001fce42b580 prev c000001fce42bdc0 mm c000001fce40fa00 prot 8000000000000104 anon_vma (null) vm_ops c008000011ddca18 pgoff 1 file c000001fe2969a00 private_data (null) flags: 0x100873(read|write|mayread|maywrite|mayexec|denywrite|account) ---- [ 9.074612] Details for VMA[3] c000001fce42b580 [ 9.074661] vma c000001fce42b580 start 00007fffcafe0000 end 00007fffcb010000 next (null) prev c000001fce42b880 mm c000001fce40fa00 prot 8000000000000104 anon_vma c000001fce4456f0 vm_ops (null) pgoff 1fffffffd file (null) private_data (null) flags: 0x100173(read|write|mayread|maywrite|mayexec|growsdown|account) [ 9.075038] CPU: 48 PID: 7544 Comm: sed Not tainted 4.14.0-dirty #154 [ 9.075104] Call Trace: [ 9.075124] [c000001fbef37840] [c000000000b17a00] dump_stack+0xb0/0xf0 (unreliable) [ 9.075212] [c000001fbef37880] [c0000000002db824] mmap_region+0x2f4/0x720 [ 9.075288] [c000001fbef37970] [c0000000002dc034] do_mmap+0x3e4/0x480 [ 9.075358] [c000001fbef379f0] [c0000000002a96c8] vm_mmap_pgoff+0xe8/0x120 [ 9.075432] [c000001fbef37ac0] [c0000000003cf378] elf_map+0x98/0x270 [ 9.075490] [c000001fbef37b60] [c0000000003d1258] load_elf_binary+0x6f8/0x158c [ 9.075591] [c000001fbef37c80] [c00000000035d320] search_binary_handler+0xd0/0x270 [ 9.075675] [c000001fbef37d10] [c00000000035f278] do_execveat_common.isra.31+0x658/0x890 [ 9.075765] [c000001fbef37df0] [c00000000035f8c0] SyS_execve+0x40/0x50 [ 9.075834] [c000001fbef37e30] [c00000000000b220] system_call+0x58/0x6c When it fails =============== [ 9.075910] 7544 (sed): Uhuuh, elf segment at 0000000010030000 requested but the memory is mapped already [ 9.076010] Total VMAs 4 on MM c000001fce40fa00 ---- [ 9.076055] Details for VMA[1] c000001fce42bdc0 [ 9.076103] vma c000001fce42bdc0 start 0000000010000000 end 0000000010020000 next c000001fce42b880 prev (null) mm c000001fce40fa00 prot 8000000000000105 anon_vma (null) vm_ops c008000011ddca18 pgoff 0 file c000001fe2969a00 private_data (null) flags: 0x875(read|exec|mayread|maywrite|mayexec|denywrite) ---- [ 9.076461] Details for VMA[2] c000001fce42b880 [ 9.076509] vma c000001fce42b880 start 0000000010020000 end 0000000010030000 next c000001fce42b7c0 prev c000001fce42bdc0 mm c000001fce40fa00 prot 8000000000000104 anon_vma (null) vm_ops c008000011ddca18 pgoff 1 file c000001fe2969a00 private_data (null) flags: 0x100873(read|write|mayread|maywrite|mayexec|denywrite|account) ---- [ 9.076867] Details for VMA[3] c000001fce42b7c0 [ 9.076925] vma c000001fce42b7c0 start 0000000010030000 end 0000000010040000 next c000001fce42b580 prev c000001fce42b880 mm c000001fce40fa00 prot 8000000000000104 anon_vma (null) vm_ops (null) pgoff 1003 file (null) private_data (null) flags: 0x100073(read|write|mayread|maywrite|mayexec|account) ----- [ 9.077285] Details for VMA[4] c000001fce42b580 [ 9.077335] vma c000001fce42b580 start 00007fffcafe0000 end 00007fffcb010000 next (null) prev c000001fce42b7c0 mm c000001fce40fa00 prot 8000000000000104 anon_vma c000001fce4456f0 vm_ops (null) pgoff 1fffffffd file (null) private_data (null) flags: 0x100173(read|write|mayread|maywrite|mayexec|growsdown|account)
