Cdylib module have function 1000 function calls during cargo test without any test defined

I am hunting a very strange behavior. In a multi module project.

The affected module is crate-type = ["cdylib"] that uses other modules, but no module uses it. It exposes in FFI. This module has just 5 external functions with '#[no_mangle]'. No tests are defined in both files or test folder.

The code uses a debugf , macro defined in dependencies, that append write some text to temp file for debug purpose.

When I execute cargo test, it panics trying to open the log file defined by debugf macro.

The function is:

#[no_mangle]
pub extern fn close(ctx_ptr: *mut FfiContext) {
    if ctx_ptr.is_null() { return }
    let ctx = unsafe { Box::from_raw(ctx_ptr) };
    debugf!("closing context");
    drop(ctx);
}

So looks like something is executing this code. Looking into the logs, I have around 1000 entries of "closing context" produced by that macro (lib.rs:59:5).

Enabling some verbose a very strange stack trace:

thread 'main' panicked at 'failed to open log file: Os { code: 24, kind: Other, message: "Too many open files" }', space-lib/src/lib.rs:59:5
stack backtrace:
   0:     0x55e28494ce64 - <unknown>
   1:     0x55e28496e0cc - <unknown>
   2:     0x55e284949bf7 - <unknown>
   3:     0x55e28494f195 - <unknown>
   4:     0x55e28494ee81 - <unknown>
   5:     0x55e28494f7fa - <unknown>
   6:     0x55e28493a78b - <unknown>
   7:     0x55e2848fb6d2 - close
.
.
.
4071:     0x55e2848fb934 - close
4072:     0x55e28493bb7f - <unknown>
4073:     0x55e28493babf - <unknown>
4074:     0x55e28493bbff - <unknown>
4075:     0x55e2848fb934 - close
4076:     0x55e28493bb7f - <unknown>
4077:     0x55e28493babf - <unknown>
4078:     0x55e28493bbff - <unknown>
4079:     0x55e2848fb934 - close
4080:     0x55e28493bb7f - <unknown>
4081:     0x55e28493babf - <unknown>
4082:     0x55e28493bbff - <unknown>
4083:     0x55e2848fb934 - close
4084:     0x55e28493bb7f - <unknown>
4085:     0x55e28493babf - <unknown>
4086:     0x55e28493bbff - <unknown>
4087:     0x55e2848fb934 - close
4088:     0x55e28492a155 - <unknown>
4089:     0x55e284929edd - <unknown>
4090:     0x55e284929cb1 - <unknown>
4091:     0x55e284934b5a - <unknown>
4092:     0x55e28490da0c - <unknown>
4093:     0x55e28491cb44 - <unknown>
4094:     0x55e28491db51 - <unknown>
4095:     0x55e2848fba72 - <unknown>
4096:     0x55e2848fb430 - <unknown>
4097:     0x55e28494f2c3 - <unknown>
4098:     0x55e284956497 - <unknown>
4099:     0x55e28494fca0 - <unknown>
4100:     0x55e2848fb409 - <unknown>
4101:     0x55e2848fbaaa - <unknown>
4102:     0x7f77526701e3 - __libc_start_main
4103:     0x55e2848fb16e - <unknown>
4104:                0x0 - <unknown>
error: test failed, to rerun pass '--lib'

You're overriding libc's close(2) function, so anything attempts to use this syscall can behave strangely.

4 Likes

It looks like you've got some sort of infinite recursion going on. Does the destructor for FfiContext indirectly call close() by any chance? Otherwise the log message indicates that the call to debugf!() has tried to open too many files, so you may want to trace through and see what debugf!() does under the hood.

Also, if you compile the library in debug mode it should give you a more useful stack trace. I think release builds don't include debug symbols by default.

EDIT: Ignore me, @Hyeonu's answer is the correct one.

Ohh.. that was bad. I was not aware of those standard methods. Something to read.

Thanks very much

In a binary, because all exported symbols are within one namespace it's common to add a known prefix to every exported function. So you might rename close() to foo_close() (assuming your library is called foo, of course).

For functions which would logically be a method in Rust or C++, it's also a good idea to prefix the function name with the type it operates on. So another possible name is ffi_context_close().

1 Like

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.