Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

moar attempts to allocate huge amounts of memory just after installation #2635

Closed
Kaiepi opened this Issue Jan 23, 2019 · 15 comments

Comments

Projects
None yet
4 participants
@Kaiepi
Copy link
Contributor

Kaiepi commented Jan 23, 2019

The Problem

MoarVM keeps throwing errors like "MoarVM panic: Memory allocation failed; could not allocate 1133629440 bytes" when I attempt to run Perl 6 for long enough. This did not happen in 2018.12.

Eventually this stops happening, but I don't know what triggers it.

Expected Behavior

Code should run like it did in 2018.12.

Actual Behavior

When I ran ktrace while attempting to run my bot, I found that it attempted to allocate 5203538026 bytes (4.85GB) total in seconds. The same happened when I tried to calculate how much memory was freed in total from the ktrace logs.

Steps to Reproduce

I can't come up with a good way to golf this. Just have Perl 6 running long enough after installing it and it'll happen eventually. I can send you the ktrace logs over IRC and give you the code I ran to cause the panic if you ask, though.

Environment

  • Operating system:
    OpenBSD bastille.kennel.qt 6.4 GENERIC.MP#364 amd64
  • Compiler version (perl6 -v):
    This is Rakudo version 2018.12-246-g5b231e099 built on MoarVM version 2018.12-36-g34fac5f4e
    implementing Perl 6.d.
@Kaiepi

This comment has been minimized.

Copy link
Contributor Author

Kaiepi commented Jan 23, 2019

Calculated how much memory was getting freed from the logs using 2018.12; it's 2357518336 bytes (2.2GB)

@lizmat

This comment has been minimized.

Copy link
Contributor

lizmat commented Jan 23, 2019

Feels to me like another case of guards being added while not seeing that they were already added, like recently with subs that had --> Nil in their signature.

@jnthn

This comment has been minimized.

Copy link
Member

jnthn commented Jan 23, 2019

Feels to me like another case of guards being added while not seeing that they were already added, like recently with subs that had --> Nil in their signature.

Except I added a guard count limit, so that class of leak can't happen any more; it'll hit a certain number of entries and then stop growing.

@AlexDaniel AlexDaniel added the BLOCKER label Jan 23, 2019

@AlexDaniel

This comment has been minimized.

Copy link
Member

AlexDaniel commented Jan 23, 2019

Eventually this stops happening, but I don't know what triggers it.

What does that mean?

@Kaiepi

This comment has been minimized.

Copy link
Contributor Author

Kaiepi commented Jan 24, 2019

What does that mean?

It means that while I was trying to debug what was going on when I first mentioned that it was happening on IRC, it suddenly stopped panicking and ran the same way it did in 2018.12.

@AlexDaniel

This comment has been minimized.

Copy link
Member

AlexDaniel commented Jan 24, 2019

Hmm… if you see it happening again, please let me know. Also, maybe if it starts happening, try it with 2018.12 also. The code is using Cro, right? Like, there's no simple short script suffering from this?

@Kaiepi

This comment has been minimized.

Copy link
Contributor Author

Kaiepi commented Jan 24, 2019

I haven't come up with any shorter than this:

The same happened when I tried to calculate how much memory was freed in total from the ktrace logs.
I can send you the ktrace logs over IRC and give you the code I ran to cause the panic if you ask, though.

@AlexDaniel AlexDaniel removed the BLOCKER label Jan 26, 2019

@AlexDaniel

This comment has been minimized.

Copy link
Member

AlexDaniel commented Jan 26, 2019

I'm removing the label for now, because we don't really have any reliable way to reproduce this and confirm that it is a new issue. But! Please keep an eye on #2644, it may be a completely unrelated issue but it does have similar memory-eating behavior. Your bot is also using Cro::WebSocket, which that other ticket is about, so actually it may be exactly the same issue we're looking at.

@Kaiepi

This comment has been minimized.

Copy link
Contributor Author

Kaiepi commented Jan 29, 2019

The issue happens with all code, but not the bot's code.; I did find a golf for triggering the panic though. In the REPL, run:

say [+] [0..1000000];
say [+] [0..1000000];

Edit: you may need to fiddle with ulimit for this to work if you have a lot of RAM

@Kaiepi

This comment has been minimized.

Copy link
Contributor Author

Kaiepi commented Feb 4, 2019

The golf no longer works on my machine on HEAD. The update to Cro::WebSocket fixed the memory issues with the bot.

@Kaiepi Kaiepi closed this Feb 4, 2019

@AlexDaniel

This comment has been minimized.

Copy link
Member

AlexDaniel commented Feb 5, 2019

Good! Please let us know if you see it again.

@Kaiepi

This comment has been minimized.

Copy link
Contributor Author

Kaiepi commented Feb 10, 2019

This issue's happening again with either my bot or Cro::WebSocket.

Backtrace (with SIGABRT being called when MVM_malloc fails to allocate memory and the JIT and spesh disabled):

#0  thrkill () at -:3
No locals.
#1  0x00000f57c8a67701 in MVM_realloc (p=0xf5892c90000, size=1287938048) at alloc.h:27
	ptr = (void *) 0x0
#2  0x00000f57c8a68a28 in set_size_internal (tc=0xf583faf1000, body=0xf5802cfd3f8, n=1287934122, repr_data=0xf57e24f75c0)
    at src/6model/reprs/VMArray.c:365
	elems = 1287933161
	start = 0
	ssize = 1287938048
	slots = (void *) 0xf5892c90000
#3  0x00000f57c8a6aa6e in asplice (tc=0xf583faf1000, st=0xf579a943aa8, root=0xf5802cfd3e0, data=0xf5802cfd3f8, from=0xf5802cfe4f0, 
    offset=1287933161, count=0) at src/6model/reprs/VMArray.c:984
	repr_data = (MVMArrayREPRData *) 0xf57e24f75c0
	body = (MVMArrayBody *) 0xf5802cfd3f8
	elems0 = 1287933161
	elems1 = 961
	start = 16871699976192
	tail = 0
#4  0x00000f57c89e381a in MVM_interp_run (tc=0xf583faf1000, initial_invoke=0xf57c8a138a6 <thread_initial_invoke>, 
    invoke_data=0xf581c4cc5a0) at src/core/interp.c:2372
	obj = (MVMObject *) 0xf5802cfd3e0
	op = 314
	LABELS = {0xf57c89d241d, 0xf57c89d245f, 0xf57c89d2461, 0xf57c89d2461, 0xf57c89d247c, 0xf57c89d2505, 0xf57c89d2520, 
  0xf57c89d25ae, 0xf57c89d2649, 0xf57c89d26df, 0xf57c89d2778, 0xf57c89d2811, 0xf57c89d28a8, 0xf57c89d2942, 0xf57c89d29dc, 
  0xf57c89d2a73, 0xf57c89d2b08, 0xf57c89d2b9e, 0xf57c89d2c33, 0xf57c89d2cc8, 0xf57c89d2d5e, 0xf57c89d2df3, 0xf57c89d2e93, 
  0xf57c89d2f31, 0xf57c89d2fb0, 0xf57c89d306a, 0xf57c89d3124, 0xf57c89d31ee, 0xf57c89d32b8, 0xf57c89d339b, 0xf57c89d347e, 
  0xf57c89d3558, 0xf57c89d3632, 0xf57c89d36f7, 0xf57c89d37bc, 0xf57c89d38eb, 0xf57c89d3b52, 0xf57c89d3d83, 0xf57c89d3e3b, 
  0xf57c89d3ef3, 0xf57c89d3fab, 0xf57c89d40db, 0xf57c89d418d, 0xf57c89d423f, 0xf57c89d42f1, 0xf57c89d43a3, 0xf57c89d43a3, 
  0xf57c89d43be, 0xf57c89d4479, 0xf57c89d4530, 0xf57c89d4a75, 0xf57c89d4ba6, 0xf57c89d4c5f, 0xf57c89d4d24, 0xf57c89d4ddd, 
  0xf57c89d4ed2, 0xf57c89d4f6a, 0xf57c89d502b, 0xf57c89d50ec, 0xf57c89d51ad, 0xf57c89d526e, 0xf57c89d532f, 0xf57c89d53f0, 
  0xf57c89d54e4, 0xf57c89d559f, 0xf57c89d565d, 0xf57c89d5719, 0xf57c89d58b1, 0xf57c89d5972, 0xf57c89d5a71, 0xf57c89d5b35, 
  0xf57c89d5bce, 0xf57c89d5c95, 0xf57c89d5d10, 0xf57c89d5d8b, 0xf57c89d5e06, 0xf57c89d5e81, 0xf57c89d5f3c, 0xf57c89d5ff7, 
  0xf57c89d60b2, 0xf57c89d614b, 0xf57c89d6206, 0xf57c89d62c1, 0xf57c89d63fe, 0xf57c89d649d, 0xf57c89d65cb, 0xf57c89d6713, 
  0xf57c89d67e3, 0xf57c89d68b3, 0xf57c89d6977, 0xf57c89d6a3b, 0xf57c89d6aff, 0xf57c89d6bc3, 0xf57c89d6cbb, 0xf57c89d6d7e, 
  0xf57c89d6e41, 0xf57c89d6f04, 0xf57c89d6fc7, 0xf57c89d70e1, 0xf57c89d7189, 0xf57c89d7291, 0xf57c89d7372, 0xf57c89d7422, 
  0xf57c89d74d2, 0xf57c89d7582, 0xf57c89d7632, 0xf57c89d76e2, 0xf57c89d7792, 0xf57c89d7842, 0xf57c89d78f2, 0xf57c89d79d3, 
  0xf57c89d7a93, 0xf57c89d7b41, 0xf57c89d7bf1, 0xf57c89d7ca1, 0xf57c89d7d51, 0xf57c89d7e11, 0xf57c89d7ec1, 0xf57c89d7f71, 
  0xf57c89d8021, 0xf57c89d80c5, 0xf57c89d816b, 0xf57c89d8214, 0xf57c89d82c9, 0xf57c89d8372, 0xf57c89d8420, 0xf57c89d84e1, 
  0xf57c89d85a2, 0xf57c89d863a, 0xf57c89d86db, 0xf57c89d877c, 0xf57c89d881d, 0xf57c89d88be, 0xf57c89d8952, 0xf57c89d89eb, 
  0xf57c89d8a91, 0xf57c89d8c38, 0xf57c89d8dfa, 0xf57c89d8fbc, 0xf57c89d917e, 0xf57c89d9340, 0xf57c89d93d5, 0xf57c89d947f, 
  0xf57c89d952b, 0xf57c89d95d5, 0xf57c89d9694, 0xf57c89d977f, 0xf57c89d986c, 0xf57c89d9957, 0xf57c89d9a4a, 0xf57c89d9b0e, 
  0xf57c89d9bd2, 0xf57c89d9c96, 0xf57c89d9d6e, 0xf57c89d9e73, 0xf57c89d9f78, 0xf57c89da07d, 0xf57c89da182, 0xf57c89da22c, 
  0xf57c89da2c5, 0xf57c89da35f, 0xf57c89da46f, 0xf57c89da4f5, 0xf57c89da59e, 0xf57c89da64b, 0xf57c89da7a6, 0xf57c89da85c, 
  0xf57c89da914, 0xf57c89daa3c, 0xf57c89daaf3, 0xf57c89dab9e, 0xf57c89dac61, 0xf57c89dad24, 0xf57c89dade7, 0xf57c89dae9a, 
  0xf57c89daf4d, 0xf57c89db000, 0xf57c89db0c1, 0xf57c89db13c, 0xf57c89db1b0, 0xf57c8a022f5, 0xf57c8a02310, 0xf57c89db26b, 
  0xf57c89db314, 0xf57c89db3a9, 0xf57c89db43e, 0xf57c89db54e, 0xf57c89db68e, 0xf57c89db7ce, 0xf57c89db910, 0xf57c89dba50, 
  0xf57c89dbc97, 0xf57c89dbdd5, 0xf57c89dbefa, 0xf57c89dc195, 0xf57c89dc27f, 0xf57c89dc34a, 0xf57c89dc3c2, 0xf57c89dc461, 
  0xf57c89dc52c...}
	cur_op = (MVMuint8 *) 0xf583925b5d0 <Address 0xf583925b5d0 out of bounds>
	bytecode_start = (MVMuint8 *) 0xf583925b4e0 <Address 0xf583925b4e0 out of bounds>
	reg_base = (MVMRegister *) 0xf57d0383a40
	cu = (MVMCompUnit *) 0xf57a39d1360
	cur_callsite = (MVMCallsite *) 0xf57c8bb6040
#5  0x00000f57c8a139ee in start_thread (data=0xf581c4cc5a0) at src/core/threads.c:87
	ts = (ThreadStart *) 0xf581c4cc5a0
	tc = (MVMThreadContext *) 0xf583faf1000
#6  0x00000f57995af0d1 in _rthread_start (v=Variable "v" is not available.
) at /usr/src/lib/librthread/rthread.c:96
	thread = Variable "thread" is not available.
@Kaiepi

This comment has been minimized.

Copy link
Contributor Author

Kaiepi commented Feb 11, 2019

This ended up being because I was using HTTP 2 requests instead of HTTP 1.1 in my bot. I don't think it should make the compiler blow up like this though

@Kaiepi Kaiepi closed this Feb 11, 2019

@Kaiepi Kaiepi reopened this Feb 11, 2019

@AlexDaniel

This comment has been minimized.

Copy link
Member

AlexDaniel commented Feb 19, 2019

@Kaiepi can you please file a ticket for Cro::WebSocket? See https://colabti.org/irclogger/irclogger_log/perl6-dev?date=2019-02-18#l201.

@Kaiepi

This comment has been minimized.

Copy link
Contributor Author

Kaiepi commented Mar 6, 2019

The issue was with Cro::HTTP, not Cro::WebSocket. I made the issue here, so I'll be closing this now.

@Kaiepi Kaiepi closed this Mar 6, 2019

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.
You signed in with another tab or window. Reload to refresh your session. You signed out in another tab or window. Reload to refresh your session.