Out of Memory 2^64

[cgutteridge]

I've a script that is crashing since our Redhat Enterprise Linux updated FreeTDS to
freetds 1.3.3-1.el7.x86_64
freetds-devel 1.3.3-1.el7.x86_64
freetds-libs 1.3.3-1.el7.x86_64
I'm using it via Perl's DBD::Sybase module.

I'm aware this might be fixed in a future version, but I'm in the world of precanned Redhat packages. I might be able to arrange install-from-source if that's the fix.

The crash is... interesting. It's giving Out of Memory, and running a strace shows it's trying to allocate
18446744071562072064 bytes.

Which is... 2^64 - 2^31 + 2^12

Which is at least interesting! Some of my friends think it might be an issue with casting, but my low level coding is rusty.

[fziglio]

Does the program crash? I suppose in this case you can enable core dump and ask the stack trace using the debugger. Otherwise I would enable FreeTDS logging and see the previous requests. Surely someone (FreeTDS, DBD::Sybase) is asking too much memory 😄

[cgutteridge]

Yes the program immediately ends with "Out of Memory" as my VM has under 16 exoBytes of RAM, but it doesn't crash, it quits politely with exit code 1.

I've run strace and this might be helpful?

sendto(5, "\27\3\3\1(\0\0\0\0\0\0\0\7@\304\356\215oxJ\210\334\2B\375Lu\232\r\22\322"..., 301, MSG_NOSIGNAL, NULL, 0) = 301
setsockopt(5, SOL_TCP, TCP_CORK, [0], 4) = 0
setsockopt(5, SOL_TCP, TCP_CORK, [1], 4) = 0
poll([{fd=5, events=POLLIN}, {fd=4, events=POLLIN}], 2, -1) = 1 ([{fd=5, revents=POLLIN}])
poll([{fd=5, events=POLLIN}, {fd=4, events=POLLIN}], 2, -1) = 1 ([{fd=5, revents=POLLIN}])
recvfrom(5, "\27\3\3\20\30", 5, MSG_NOSIGNAL, NULL, NULL) = 5
poll([{fd=5, events=POLLIN}, {fd=4, events=POLLIN}], 2, -1) = 1 ([{fd=5, revents=POLLIN}])
recvfrom(5, "\0\0\0\0\0\0\0\7\230V\276\212\355\215\231e\314y\253-\262k&\243\206@\375\210\377 \224\r"..., 4120, MSG_NOSIGNAL, NULL, NULL) = 4120
mmap(NULL, 18446744071562072064, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mmap(NULL, 18446744071562203136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mmap(NULL, 134217728, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f9976f42000
munmap(0x7f9976f42000, 17555456) = 0
munmap(0x7f997c000000, 49553408) = 0
mprotect(0x7f9978000000, 135168, PROT_READ|PROT_WRITE) = 0
mmap(NULL, 18446744071562072064, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory)
write(2, "Out of memory!\n", 15Out of memory!
`

[fziglio]

I cannot understand much. The traffic is encrypted (I can see TLS data). There's no "Out of memory!" string in either FreeTDS (there's one but on an application, not a library) or DBD::Sybase source. So I suppose it could be a library (like OpenSSL) or Perl, but I cannot guarantee. Try to use logging https://www.freetds.org/userguide/logging.html.

[cgutteridge]

Thanks. I've now turned on logging. It appears to do the SELECT and then tries to set up the table in memory using token.c it then tries to allocate an insane amount of memory, fails and exits cleanly. If I remove both TEXT fields from the SELECT query it then works.

The TEXT fields are coming out at 2Gb so it's possible this is having some kind of overflow error? I definitely set "text size" in /etc/freetds.conf

As the memory it's trying to allocate is roughly 2^64 - 2 x 2^30 , that suggests that something odd's happening and maybe it's overflowing an int field, but my C coding is rusty.

token.c:1619: name size/wsize type/wtype utype
token.c:1620: -------------------- --------------- --------------- -------
token.c:1625: event_id 4/4 56/56 0
token.c:1625: poster_id 256/64 39/167 0
token.c:1625: title 1020/255 39/167 0
token.c:1625: full_text 2147483647/1073741823 39/231 0
token.c:1625: url 400/100 39/167 0
token.c:1625: posted_date 8/8 61/61 0
token.c:1625: expiry_date 8/8 61/61 0
token.c:1625: brief_title 480/120 39/167 0
token.c:1625: abstract 2147483647/1073741823 39/231 0
token.c:1625: last_edit 4/4 56/56 0
util.c:179:Changed query state from READING to PENDING
ct.c:1271:ct_results() process_result_tokens returned 0 (type 4049)
token.c:555:tds_process_tokens(0x20375b0, 0x7fff0df6b6d0, 0x7fff0df6b6d4, 0x6a14)
util.c:179:Changed query state from PENDING to READING
token.c:570:processing result tokens. marker is d1(ROW)
token.c:676:tds_process_tokens::SET_RETURN stopping on current token
util.c:179:Changed query state from READING to PENDING
ct.c:1271:ct_results() process_result_tokens returned 0 (type 4040)
ct.c:2476:ct_res_info(0x2054cb0, 803, 0x7fff0df6b78c, -99999, (nil))
ct.c:2495:ct_res_info(): Number of columns is 10
ct.c:2414:ct_describe(0x2054cb0, 1, 0x2051010)
ct.c:1999:_ct_get_client_type(type 56, user 0, size 4)
ct.c:2433:ct_describe() datafmt->datatype = 8 server type 56
ct.c:1564:ct_bind(0x2054cb0, 1, 0x2051010, 0x2050d40, 0x2050d6c, 0x2050d30)
ct.c:1566:ct_bind() datafmt count = 1 column_number = 1
ct.c:2414:ct_describe(0x2054cb0, 2, 0x20510c0)
ct.c:1999:_ct_get_client_type(type 39, user 0, size 256)
ct.c:2433:ct_describe() datafmt->datatype = 0 server type 39
ct.c:1564:ct_bind(0x2054cb0, 2, 0x20510c0, 0x20666e0, 0x2050db4, 0x2050d78)
ct.c:1566:ct_bind() datafmt count = 1 column_number = 2
ct.c:2414:ct_describe(0x2054cb0, 3, 0x2051170)
ct.c:1999:_ct_get_client_type(type 39, user 0, size 1020)
ct.c:2433:ct_describe() datafmt->datatype = 0 server type 39
ct.c:1564:ct_bind(0x2054cb0, 3, 0x2051170, 0x2051700, 0x2050dfc, 0x2050dc0)
ct.c:1566:ct_bind() datafmt count = 1 column_number = 3
ct.c:2414:ct_describe(0x2054cb0, 4, 0x2051220)
ct.c:1999:_ct_get_client_type(type 39, user 0, size 2147483647)
ct.c:2433:ct_describe() datafmt->datatype = 0 server type 39
ct.c:1955:ct_close(0x1fe6550, 301)
query.c:3757:tds_disconnect()
tls.c:202:GNUTLS: level 5:
REC[0x204d8c0]: Start of epoch cleanup
tls.c:202:GNUTLS: level 5:
REC[0x204d8c0]: End of epoch cleanup
tls.c:202:GNUTLS: level 5:
REC[0x204d8c0]: Epoch #1 freed
util.c:179:Changed query state from PENDING to DEAD
mem.c:656:tds_free_all_results()
ct.c:1968:ct_con_drop(0x1fe6550)

[fziglio]

Looking at the code of DBD::Sybase it seems it tries to allocate memory based on maxlength, but without constraints maxlength is 2GB-1 which could cause that issue. Try to see https://metacpan.org/pod/DBD::Sybase what it's said about TEXTSIZE. Either using set textsize xxx or using LongReadLen should solve the issue. Unfortunately it would be better if DBD::Sybase follow a more dynamic approach instead of trying to allocate enough memory for any possible future possibility.

[cgutteridge]

Ah, those don't work but yes, it sounds like a bug in DBD::Sybase that may have been fixed but RHEL versions lag
mpeppler/DBD-Sybase#68

[cgutteridge]

Ah, updating to the latest DBD::Sybase seems to have fixed it. Thanks for your time. Sorry it wasn't actually your problem!
(By the way, we've been using FreeTDS for 20+ years now!)