#884829 xserver-xorg-video-nouveau: memory leak in Xorg when audacious is playing with Info Bar Visualization

Package:
xserver-xorg-core
Source:
xorg-server
Description:
Xorg X server - core server
Submitter:
Jun MO
Date:
2017-12-24 05:33:03 UTC
Severity:
normal
#884829#5
Date:
2017-12-20 07:05:46 UTC
From:
To:
Dear Maintainer,

I am filing this bug report on nouveau because this problem
  a) can be reproduced when using nouveau, and
  b) can not be reproduced when using vesa, fbdev or nvidia(nvidia-legacy-340xx).
If it is not a bug of nouveau, please help to assign to the right package.

My Desktop Environment is Xfce4. The Interface of audacious is "GTK
Interface". In case you are not familiar with audacious, "Info Bar
Visualization" is in the lower right part of audacious(see [1]).

1. Reproduce
  1) Relogin X session.
  2) Open audacious. Set Repeat play(Ctrl+R). Set Show Info Bar
    Visualization(View -> Show Info Bar Visualization).
  3) Play some audio file in audacious. Meanwhile use
      $ ps -o vsz,rss -p $( pgrep Xorg )
    to monitor the memory of Xorg.

  Then one can observe the memory of Xorg is slowly increasing. The rate can be
  measured as ~10K/s(depend on which file is playing).

2. Valgrind memcheck
  I use these steps to run valgrind on Xorg. The result is attached as
  Xorg-memcheck.txt. Audacious have been played about 15 minutes when
  getting this result.

  1) $ sudo dpkg-divert --local --rename --divert /usr/lib/xorg/Xorg.valgrind-testing /usr/lib/xorg/Xorg
     Then write /usr/lib/xorg/Xorg as:

#!/bin/sh
exec valgrind --error-limit=no --log-file=/var/log/Xorg-memcheck.txt --leak-check=full /usr/lib/xorg/Xorg.valgrind-testing "$@"

  2) Relogin X session.
  3) Run steps in 1. Reproduce.
  4) Relogin X session.

3. Gdb backtrace
  I use these steps to get a gdb backtrace on Xorg. The result is attached as
  xorg-gdb.txt.

  1) Write a file of xorg.gdb as:

# beginnig of xorg.gdb
set pagination off

b pixman_rect_alloc
disable 1
commands 1
  silent
  bt
  bt full
  detach
  quit
end

b RegionSubtract
disable 2
commands 2
  silent
  enable 1
  continue
end

b exaCopyNtoN
disable 3
commands 3
  silent
  enable 2
  continue
end

b damageCopyArea
commands 4
  silent
  enable 3
  continue
end

continue
# end of xorg.gdb

  2) While audacious is playing, run
     $ sleep 5 ; sudo gdb --batch --command=xorg.gdb -p $( pgrep Xorg ) &> xorg-gdb.txt

[1] https://screenshots.debian.net/screenshots/000/015/415/large.png

Regrads,
Jun MO

#884829#10
Date:
2017-12-21 20:29:24 UTC
From:
To:
Control: reassign -1 xserver-xorg-core 2:1.19.5-1

That's probably because those drivers do not support the exa
acceleration method.  Your valgrind log shows that the leaks happen in
damageCopyArea() which calls exaCopyarea() and then some other exa*
functions.  There is no code from the nouveau DDX involved here AFAICS.

I am reassigning it to the xserver-xorg-core package.  Hopefully
somebody who knows more about X than I do can give further help.

Cheers,
       Sven

#884829#21
Date:
2017-12-24 05:31:40 UTC
From:
To:
Thanks Joachim for reassigning this bug.

And I am providing further informations and a walk around.

I probably have found exactly where the memory blocks are loss.
The postion is after FreePixmap() at pixmap.c:133.

This can be verified using Valgrind and GDB.
A detailed log is attached as xorg-vgdb.txt. Below is explanation.
I have rebuilt the xorg-server package with
DEB_CFLAGS_MAINT_APPEND="-O0 -g3" before running the test.

 (gdb) target remote | vgdb
 (gdb) b pixmap.c:132
 (gdb) c
 (gdb) n
133	in ../../../../dix/pixmap.c

Then run leak_check to set increment count of valgrind to zero:

 (gdb) monitor leak_check summary reachable
 (gdb) c

Then hit at pixmap.c:132 again:

Thread 1 hit Breakpoint 1, FreePixmap (pPixmap=0x13cb2170)
    at ../../../../dix/pixmap.c:132
132	in ../../../../dix/pixmap.c
 (gdb) monitor leak_check reachable
==13478== 224 (+224) bytes in 1 (+1) blocks are still reachable in
loss record 2,567 of 3,164
==13478==    at 0x4C2ABEF: malloc (vg_replace_malloc.c:299)
==13478==    by 0x5E5FABA: pixman_rect_alloc (pixman-region.c:465)
==13478==    by 0x5E60F8B: pixman_op (pixman-region.c:828)
==13478==    by 0x5E62858: pixman_region_subtract (pixman-region.c:1987)
==13478==    by 0xAC09408: RegionSubtract (regionstr.h:271)
==13478==    by 0xAC097F5: exaCopyDirty (exa_migration_classic.c:128)
==13478==    by 0xAC09EDE: exaCopyDirtyToFb (exa_migration_classic.c:303)
==13478==    by 0xAC0C948: exaDoMigration_mixed (exa_migration_mixed.c:118)
==13478==    by 0xAC08536: exaDoMigration (exa.c:1132)
==13478==    by 0xAC0E928: exaHWCopyNtoN (exa_accel.c:468)
==13478==    by 0xAC0EED8: exaCopyNtoN (exa_accel.c:581)
==13478==    by 0x32A84B: miCopyRegion (micopy.c:121)
==13478==    by 0x32ADB2: miDoCopy (micopy.c:296)
==13478==    by 0xAC0F01B: exaCopyArea (exa_accel.c:608)
==13478==    by 0x2A32E5: damageCopyArea (damage.c:775)
==13478==    by 0x15A757: ProcCopyArea (dispatch.c:1722)
==13478==    by 0x156F48: Dispatch (dispatch.c:479)
==13478==    by 0x166152: dix_main (main.c:287)
==13478==    by 0x146B91: main (stubmain.c:34)
==13478==
==13478== 26,200 (+200) bytes in 131 (+1) blocks are still reachable
in loss record 3,126 of 3,164
==13478==    at 0x4C2ABEF: malloc (vg_replace_malloc.c:299)
==13478==    by 0x1899A5: AllocatePixmap (pixmap.c:119)
==13478==    by 0xB451823: fbCreatePixmapBpp (fbpixmap.c:53)
==13478==    by 0xB4519F3: fbCreatePixmap (fbpixmap.c:97)
==13478==    by 0xAC0B97D: exaCreatePixmap_mixed (exa_mixed.c:63)
==13478==    by 0x159A7F: ProcCreatePixmap (dispatch.c:1441)
==13478==    by 0x156F48: Dispatch (dispatch.c:479)
==13478==    by 0x166152: dix_main (main.c:287)
==13478==    by 0x146B91: main (stubmain.c:34)
==13478==
==13478== LEAK SUMMARY:
==13478==    definitely lost: 119,574 (+0) bytes in 585 (+0) blocks
==13478==    indirectly lost: 2,591 (+0) bytes in 38 (+0) blocks
==13478==      possibly lost: 23,658 (+0) bytes in 193 (+0) blocks
==13478==    still reachable: 14,784,670 (+424) bytes in 21,242 (+2) blocks
==13478==         suppressed: 0 (+0) bytes in 0 (+0) blocks
==13478==

There is no memory loss, but 2 new reachable memory blocks.
What related to my issue is the one alloc'd by malloc() which is
called by pixman_rect_alloc():

 (gdb) monitor block_list 2567
==13478== 224 (+224) bytes in 1 (+1) blocks are still reachable in
loss record 2,567 of 3,164
==13478==    at 0x4C2ABEF: malloc (vg_replace_malloc.c:299)
==13478==    by 0x5E5FABA: pixman_rect_alloc (pixman-region.c:465)
####### backtrace removed for clarify #######
==13478== 0x13CC2CC0[224]

0x13CC2CC0[224] is only referenced by *0x13cb2218:

 (gdb) monitor who_points_at 0x13cc2cc0
==13478== Searching for pointers to 0x13cc2cc0
==13478== *0x13cb2218 points at 0x13cc2cc0
 Address 0x13cb2218 is 168 bytes inside a block of size 200 alloc'd
==13478==    at 0x4C2ABEF: malloc (vg_replace_malloc.c:299)
==13478==    by 0x1899A5: AllocatePixmap (pixmap.c:119)
==13478==    by 0xB451823: fbCreatePixmapBpp (fbpixmap.c:53)
==13478==    by 0xB4519F3: fbCreatePixmap (fbpixmap.c:97)
==13478==    by 0xAC0B97D: exaCreatePixmap_mixed (exa_mixed.c:63)
==13478==    by 0x159A7F: ProcCreatePixmap (dispatch.c:1441)
==13478==    by 0x156F48: Dispatch (dispatch.c:479)
==13478==    by 0x166152: dix_main (main.c:287)
==13478==    by 0x146B91: main (stubmain.c:34)

0x13cb2218 is related to pPixmap->devPrivates:
(the offset 0x18 is found by testing on pExaPixmap in exaDestroyPixmap_mixed();
its value may not fixed on 0x18)

 (gdb) p &(((ExaPixmapPrivPtr) (((void *)
pPixmap->devPrivates)+0x18))->validSys.data)
$3 = (pixman_region16_data_t **) 0x13cb2218

 (gdb) p *((ExaPixmapPrivPtr) (((void *) pPixmap->devPrivates)+0x18))
$1 = {area = 0x0, score = 0, use_gpu_copy = 1, sys_ptr = 0x0,
  sys_pitch = 440, fb_ptr = 0x0, fb_pitch = 448, fb_size = 0,
  accel_blocked = 0, pDamage = 0x0, validSys = {extents = {
      x1 = 0, y1 = 0, x2 = 110, y2 = 80}, data = 0x13cc2cc0},
  validFB = {extents = {x1 = 0, y1 = 0, x2 = 110, y2 = 80},
    data = 0x0}, driverPriv = 0x0}

After step over pixmap.c:133, there is loss of one memory block:

 (gdb) n
133	in ../../../../dix/pixmap.c
 (gdb) monitor leak_check reachable
==13478== 106,832 (+224) bytes in 466 (+1) blocks are definitely lost
in loss record 3,153 of 3,164
==13478==    at 0x4C2ABEF: malloc (vg_replace_malloc.c:299)
==13478==    by 0x5E5FABA: pixman_rect_alloc (pixman-region.c:465)
==13478==    by 0x5E60F8B: pixman_op (pixman-region.c:828)
==13478==    by 0x5E62858: pixman_region_subtract (pixman-region.c:1987)
==13478==    by 0xAC09408: RegionSubtract (regionstr.h:271)
==13478==    by 0xAC097F5: exaCopyDirty (exa_migration_classic.c:128)
==13478==    by 0xAC09EDE: exaCopyDirtyToFb (exa_migration_classic.c:303)
==13478==    by 0xAC0C948: exaDoMigration_mixed (exa_migration_mixed.c:118)
==13478==    by 0xAC08536: exaDoMigration (exa.c:1132)
==13478==    by 0xAC0E928: exaHWCopyNtoN (exa_accel.c:468)
==13478==    by 0xAC0EED8: exaCopyNtoN (exa_accel.c:581)
==13478==    by 0x32A84B: miCopyRegion (micopy.c:121)
==13478==    by 0x32ADB2: miDoCopy (micopy.c:296)
==13478==    by 0xAC0F01B: exaCopyArea (exa_accel.c:608)
==13478==    by 0x2A32E5: damageCopyArea (damage.c:775)
==13478==    by 0x15A757: ProcCopyArea (dispatch.c:1722)
==13478==    by 0x156F48: Dispatch (dispatch.c:479)
==13478==    by 0x166152: dix_main (main.c:287)
==13478==    by 0x146B91: main (stubmain.c:34)
==13478==
==13478== LEAK SUMMARY:
==13478==    definitely lost: 119,798 (+224) bytes in 586 (+1) blocks
==13478==    indirectly lost: 2,591 (+0) bytes in 38 (+0) blocks
==13478==      possibly lost: 23,658 (+0) bytes in 193 (+0) blocks
==13478==    still reachable: 14,784,246 (-424) bytes in 21,240 (-2) blocks
==13478==         suppressed: 0 (+0) bytes in 0 (+0) blocks
==13478==

This lost block is 0x13CC2CC0[224]:

 (gdb) monitor block_list 3153
==13478== 106,832 (+224) bytes in 466 (+1) blocks are definitely lost
in loss record 3,153 of 3,164
==13478==    at 0x4C2ABEF: malloc (vg_replace_malloc.c:299)
==13478==    by 0x5E5FABA: pixman_rect_alloc (pixman-region.c:465)
####### backtrace removed for clarify #######
==13478== 0x90FA410[224]
==13478== 0x90FD240[256]
####################### MANY LINES REMOVED #################
==13478== 0x13CC2CC0[224]
####################### MANY LINES REMOVED #################
==13478== 0x16EB5F70[256]
==13478== 0x176A4C10[256]

This is no surprised as the block, 0x13CC2CC0[224], is only referenced
in some point in pPixmap; so after pPixmap is freed, the block will be
lost.

Walk around

After apply the patch below, valgrind no longer report the same memory leak.
And there is no obvious increment of memory of Xorg after running for ~4 hour.
Though I am not sure whether this patch will or will not cause other problem.
--- a/exa/exa_mixed.c +++ b/exa/exa_mixed.c @@ -266,6 +266,16 @@ pExaPixmap->sys_ptr = NULL; pExaPixmap->pDamage = NULL; } + + if(pExaPixmap->validSys.data != NULL && pExaPixmap->validSys.data != &RegionEmptyData) { + free(pExaPixmap->validSys.data); + pExaPixmap->validSys.data = NULL; + } + + if(pExaPixmap->validFB.data != NULL && pExaPixmap->validFB.data != &RegionEmptyData) { + free(pExaPixmap->validFB.data); + pExaPixmap->validFB.data = NULL; + } } swap(pExaScr, pScreen, DestroyPixmap); Jun MO