[request-tracker-maintainers] Bug#623553: Bug#623553: duplicate email addresses lead to major memory leaks

[Dominic Hargreaves]

On Thu, Apr 21, 2011 at 02:35:52AM -0400, Antoine Beaupre wrote:
> Under very specific circumstances, RT can start eating up all memory on the
> server. Load would shoot up as mason processes (in fcgid mode) would eat all
> available memory and CPU.
> 
>   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
> 14991 www-data  20   0 1301m 1.1g 5028 R   89 14.6   3:53.97 mason_handler.f
> 15002 www-data  20   0 1235m 1.1g 5028 R   81 13.7   3:28.32 mason_handler.f
> 14983 www-data  20   0 1346m 1.2g 5028 R   79 15.2   3:49.92 mason_handler.f
> 
> Strace on those process shows seemingly random data being read on the #4 file descriptor:
> 
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> poll([{fd=4, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=4, revents=POLLIN}])
> rt_sigprocmask(SIG_BLOCK, [PIPE], [], 8) = 0
> read(4, "\27\3\1\0 "..., 5)             = 5
> read(4, "V\241\232\305\35r\271c'\307\311\266\212\267\2329\221\35\212\262 \34\351\20c\233\264\10!-\3 30V"..., 32) = 32
> read(4, "\27\3\1\0000"..., 5)           = 5
> read(4, "\235s\262RE!\314\314\1\263\10\200K\325\343\272\312\23\212=Ei\373\336\23M\365uP\245\301jI".  .., 48) = 48
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> rt_sigprocmask(SIG_BLOCK, [PIPE], [], 8) = 0
> write(4, "\27\3\1\0 \30\36\3030\224lH\373E\217\311\3115\25H\215\327\272W\263[a\224\251\250|\353\200 "..., 74) = 74
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> poll([{fd=4, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=4, revents=POLLIN}]) 
> rt_sigprocmask(SIG_BLOCK, [PIPE], [], 8) = 0
> read(4, "\27\3\1\0 "..., 5)             = 5
> read(4, "\250H\271D~\221\345\24\34\376\277\325ZC\336+\362;\222.\355x\316\270\351'\257\377\237\273,\ 226"..., 32) = 32
> read(4, "\27\3\1\0000"..., 5)           = 5
> 
> That stuff is actually the wire protocol for PostgreSQL. From the pgsql side,
> the socket looks mostly idle, except for SELECT queries that happen sometime.
> This is the query:
> 
> SELECT main.* FROM Attributes main  WHERE (main.ObjectType = 'RT::User') AND (main.ObjectId = 77)
> 
> Now, the peculiar thing is that the user #77 has the *same* email address as
> user #32 (my regular user). I do not understand how this was allowed, but I did
> change the email address on account #32 today.
> 
> One way to trigger the bug is to visit the "ModifyPeople" page of a ticket that
> has user #32 as an owner, for example:
> 
> https://rt.koumbit.net/rt/Ticket/ModifyPeople.html?id=77584
> 
> Incoming emails were also triggering the bug, which made it really nastier...
> 
> The workaround was for me to change the email address on user #77 to some
> unique string.
> 
> Sorry if this is not really relevant for the Debian package, but it's really
> late here and I've just spent the last 4h tracking this bug. I figured other
> people could use that debugging info to fix the issue on their side too. :)
> 
> Oh, and note that this is present in 3.8.7 and 3.8.10 also... I tried the
> unstable packages out of desperation. :)

Thanks for the report. I wonder whether this is the same problem I've 
had in one of my installations. I didn't manage the same detailed
investigation as you, but instead developed a patch to cause the
affected workers to shut down:

<http://issues.bestpractical.com/Ticket/Display.html?id=15108>

It'll be interesting to see if we have any duplicate email addresses
in our database -- and then try and do some more investigation to
work out why this bad data is causing the memory bloat.
 
> -- Package-specific info:
> Changed files:
> 
> There are locally modified files in /usr/local/share/request-tracker3.8/,
>  these may (or may not) be the source of the problem.

Could you confirm which files you have modified, and how, so we can
be sure we know which code you were testing with?

-- 
Dominic Hargreaves | http://www.larted.org.uk/~dom/
PGP key 5178E2A5 from the.earth.li (keyserver,web,email)