Sockets test failed

[anatolykhelmer]

Compilation was OK:

cmake -DCMAKE_BUILD_TYPE=RELEASE ../fastcgipp-master -- The CXX compiler identification is GNU 5.4.0 -- Check for working CXX compiler: /usr/bin/c++ -- Check for working CXX compiler: /usr/bin/c++ -- works -- Detecting CXX compiler ABI info -- Detecting CXX compiler ABI info - done -- Detecting CXX compile features -- Detecting CXX compile features - done -- Could NOT find Doxygen (missing: DOXYGEN_EXECUTABLE) -- Configuring done -- Generating done -- Build files have been written to: /home/anatoly/CppProjects/fastcgi++.build

make Scanning dependencies of target fastcgipp [ 9%] Building CXX object CMakeFiles/fastcgipp.dir/src/log.cpp.o [ 18%] Building CXX object CMakeFiles/fastcgipp.dir/src/block.cpp.o [ 27%] Building CXX object CMakeFiles/fastcgipp.dir/src/http.cpp.o [ 36%] Building CXX object CMakeFiles/fastcgipp.dir/src/protocol.cpp.o [ 45%] Building CXX object CMakeFiles/fastcgipp.dir/src/sockets.cpp.o [ 54%] Building CXX object CMakeFiles/fastcgipp.dir/src/transceiver.cpp.o [ 63%] Building CXX object CMakeFiles/fastcgipp.dir/src/fcgistreambuf.cpp.o [ 72%] Building CXX object CMakeFiles/fastcgipp.dir/src/webstreambuf.cpp.o [ 81%] Building CXX object CMakeFiles/fastcgipp.dir/src/request.cpp.o [ 90%] Building CXX object CMakeFiles/fastcgipp.dir/src/manager.cpp.o [100%] Linking CXX shared library libfastcgipp.so [100%] Built target fastcgipp

make tests [ 52%] Built target fastcgipp Scanning dependencies of target sockets_test [ 57%] Building CXX object CMakeFiles/sockets_test.dir/tests/sockets.cpp.o [ 61%] Linking CXX executable sockets_test [ 61%] Built target sockets_test Scanning dependencies of target fcgistreambuf_test [ 66%] Building CXX object CMakeFiles/fcgistreambuf_test.dir/tests/fcgistreambuf.cpp.o [ 71%] Linking CXX executable fcgistreambuf_test [ 71%] Built target fcgistreambuf_test Scanning dependencies of target http_test [ 76%] Building CXX object CMakeFiles/http_test.dir/tests/http.cpp.o [ 80%] Linking CXX executable http_test [ 80%] Built target http_test Scanning dependencies of target transceiver_test [ 85%] Building CXX object CMakeFiles/transceiver_test.dir/tests/transceiver.cpp.o [ 90%] Linking CXX executable transceiver_test [ 90%] Built target transceiver_test Scanning dependencies of target protocol_test [ 95%] Building CXX object CMakeFiles/protocol_test.dir/tests/protocol.cpp.o [100%] Linking CXX executable protocol_test [100%] Built target protocol_test Scanning dependencies of target tests [100%] Built target tests

Failing tests:

Running tests... Test project /home/anatoly/CppProjects/fastcgi++.build Start 1: protocol 1/5 Test #1: protocol ......................... Passed 0.00 sec Start 2: http 2/5 Test #2: http ............................. Passed 4.01 sec Start 3: sockets 3/5 Test #3: sockets ..........................***Failed 1.88 sec Start 4: transceiver 4/5 Test #4: transceiver ...................... Passed 0.20 sec Start 5: fcgistreambuf 5/5 Test #5: fcgistreambuf .................... Passed 0.00 sec

80% tests passed, 1 tests failed out of 5

Total Test time (real) = 6.10 sec

The following tests FAILED: 3 - sockets (Failed) Errors while running CTest Makefile:127: recipe for target 'test' failed make: *** [test] Error 8

Operation System:

Ubuntu 16.04

[eddic]

Can you share the standard out of the test? run

./sockets_test

[anatolykhelmer]

Yes, here it is.

Jul 01 20:17:29 ubuntu2 ./sockets_test[7005] [fail]: There are leftover file descriptors after they should all have been closed

[eddic]

Hmmmm. That's interesting. Not catastrophic but unusual none the less. Try building in full debug mode with

cmake -DCMAKE_BUILD_TYPE=DEBUG -D LOG_LEVEL:INT=4 ../fastcgipp-master
make clean
make all tests
./sockets_test

and post the output of that

[anatolykhelmer]

Here it is:

Jul 01 20:22:50 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::SocketGroup(): Initialized Jul 01 20:22:50 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::SocketGroup(): Initialized Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Incoming sockets ======== 0 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Outgoing sockets ======== 512 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Locally closed sockets == 480 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Remotely closed sockets = 32 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Remaining sockets ======= 0 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Bytes sent ===== 388195328 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Bytes received = 388195328 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Incoming sockets ======== 512 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Outgoing sockets ======== 0 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Locally closed sockets == 32 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Remotely closed sockets = 480 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Remaining sockets ======= 0 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Bytes sent ===== 388195328 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [diagnostic]: SocketGroup::~SocketGroup(): Bytes received = 388195328 Jul 01 20:22:53 ubuntu2 ./sockets_test[7247] [fail]: There are leftover file descriptors after they should all have been closed

[eddic]

K. Try adding something like

INFO_LOG("Starting with " << initialFds << " file descriptors");

after line 348 and

INFO_LOG("Ending with " << openfds() << " file descriptors");

after line 362. Post the output.

[anatolykhelmer]

Here it is: Jul 01 21:03:45 ubuntu2 ./sockets_test[7741] [info]: Starting with 6 file descriptors Jul 01 21:03:45 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::SocketGroup(): Initialized Jul 01 21:03:45 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::SocketGroup(): Initialized Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Incoming sockets ======== 0 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Outgoing sockets ======== 512 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Locally closed sockets == 479 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Remotely closed sockets = 33 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Remaining sockets ======= 0 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Bytes sent ===== 389749760 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Bytes received = 389749760 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Incoming sockets ======== 512 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Outgoing sockets ======== 0 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Locally closed sockets == 33 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Remotely closed sockets = 479 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Remaining sockets ======= 0 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Bytes sent ===== 389749760 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [diagnostic]: SocketGroup::~SocketGroup(): Bytes received = 389749760 Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [info]: Ending with 7 file descriptors Jul 01 21:03:47 ubuntu2 ./sockets_test[7741] [fail]: There are leftover file descriptors after they should all have been closed

[eddic]

Huh. Interesting. One file descriptor left over that shouldn't be. I made the test rigid as far as file descriptors being closed to avoid something akin to memory leaks but was suspicious that things might not always even out given the the OS' freedom to complete closure at it's leisure. I haven't been able to reproduce this issue but it may be something that other people will experience as well.

Keep in mind that this error isn't telling you that things will be broken when you use fastcgi++. It's just saying things are not looking as "cleaned up" as they should be. I can't really offer any insight into why that last file descriptor isn't being cleaned up but it's certainly something you might be able to shed light on with a little exploration. Otherwise I'd just ignore it for now.

[Erroneous1]

All tests pass on Arch Linux on the current master branch. Is this still an issue on Ubuntu?

[Erroneous1]

I take that back. It passes on my development machine but not my build server. Incoming PR.

[eddic]

I'm going to go ahead and assume commit ed6a166d solves this.