From bc49140bab90e562dfff8a30f99e647c11779b30 Mon Sep 17 00:00:00 2001 From: Michael Lotz Date: Sun, 2 Aug 2015 20:31:50 +0200 Subject: [PATCH] tcp: Add APICall trace entry and move TRACEs into locked parts. The APICall trace entry just records the function name but this is enough to deduce where some of the state changes come from. Also move the TRACE macros past the MutexLockers to ensure that their output happens at the time when the methods actually run. --- .../network/protocols/tcp/TCPEndpoint.cpp | 73 +++++++++++++++---- 1 file changed, 57 insertions(+), 16 deletions(-) diff --git a/src/add-ons/kernel/network/protocols/tcp/TCPEndpoint.cpp b/src/add-ons/kernel/network/protocols/tcp/TCPEndpoint.cpp index cfbb271dc1..61f010adf8 100644 --- a/src/add-ons/kernel/network/protocols/tcp/TCPEndpoint.cpp +++ b/src/add-ons/kernel/network/protocols/tcp/TCPEndpoint.cpp @@ -274,6 +274,29 @@ protected: tcp_state fState; }; +class APICall : public AbstractTraceEntry { +public: + APICall(TCPEndpoint* endpoint, const char* which) + : + fEndpoint(endpoint), + fWhich(which), + fState(endpoint->State()) + { + Initialized(); + } + + virtual void AddDump(TraceOutput& out) + { + out.Print("tcp:%p (%12s) api call: %s", fEndpoint, + name_for_state(fState), fWhich); + } + +protected: + TCPEndpoint* fEndpoint; + const char* fWhich; + tcp_state fState; +}; + } // namespace TCPTracing # define T(x) new(std::nothrow) TCPTracing::x @@ -434,6 +457,8 @@ TCPEndpoint::TCPEndpoint(net_socket* socket) TCPEndpoint::_DelayedAcknowledgeTimer, this); gStackModule->init_timer(&fTimeWaitTimer, TCPEndpoint::_TimeWaitTimer, this); + + T(APICall(this, "constructor")); } @@ -441,6 +466,8 @@ TCPEndpoint::~TCPEndpoint() { mutex_lock(&fLock); + T(APICall(this, "destructor")); + _CancelConnectionTimers(); gStackModule->cancel_timer(&fTimeWaitTimer); T(TimerSet(this, "time-wait", -1)); @@ -476,6 +503,7 @@ status_t TCPEndpoint::Open() { TRACE("Open()"); + T(APICall(this, "open")); status_t status = ProtocolSocket::Open(); if (status < B_OK) @@ -492,10 +520,11 @@ TCPEndpoint::Open() status_t TCPEndpoint::Close() { - TRACE("Close()"); - MutexLocker locker(fLock); + TRACE("Close()"); + T(APICall(this, "close")); + if (fState == LISTEN) delete_sem(fAcceptSemaphore); @@ -533,10 +562,11 @@ TCPEndpoint::Close() void TCPEndpoint::Free() { - TRACE("Free()"); - MutexLocker _(fLock); + TRACE("Free()"); + T(APICall(this, "free")); + if (fState <= SYNCHRONIZE_SENT) return; @@ -557,13 +587,14 @@ TCPEndpoint::Free() status_t TCPEndpoint::Connect(const sockaddr* address) { - TRACE("Connect() on address %s", PrintAddress(address)); - if (!AddressModule()->is_same_family(address)) return EAFNOSUPPORT; MutexLocker locker(fLock); + TRACE("Connect() on address %s", PrintAddress(address)); + T(APICall(this, "connect")); + if (gStackModule->is_restarted_syscall()) { bigtime_t timeout = gStackModule->restore_syscall_restart_timeout(); status_t status = _WaitForEstablished(locker, timeout); @@ -635,10 +666,11 @@ TCPEndpoint::Connect(const sockaddr* address) status_t TCPEndpoint::Accept(struct net_socket** _acceptedSocket) { - TRACE("Accept()"); - MutexLocker locker(fLock); + TRACE("Accept()"); + T(APICall(this, "accept")); + status_t status; bigtime_t timeout = absolute_timeout(socket->receive.timeout); if (gStackModule->is_restarted_syscall()) @@ -679,6 +711,7 @@ TCPEndpoint::Bind(const sockaddr *address) MutexLocker lock(fLock); TRACE("Bind() on address %s", PrintAddress(address)); + T(APICall(this, "bind")); if (fState != CLOSED) return EISCONN; @@ -690,9 +723,11 @@ TCPEndpoint::Bind(const sockaddr *address) status_t TCPEndpoint::Unbind(struct sockaddr *address) { - TRACE("Unbind()"); - MutexLocker _(fLock); + + TRACE("Unbind()"); + T(APICall(this, "unbind")); + return fManager->Unbind(this); } @@ -700,10 +735,11 @@ TCPEndpoint::Unbind(struct sockaddr *address) status_t TCPEndpoint::Listen(int count) { - TRACE("Listen()"); - MutexLocker _(fLock); + TRACE("Listen()"); + T(APICall(this, "listen")); + if (fState != CLOSED && fState != LISTEN) return B_BAD_VALUE; @@ -731,10 +767,11 @@ TCPEndpoint::Listen(int count) status_t TCPEndpoint::Shutdown(int direction) { - TRACE("Shutdown(%i)", direction); - MutexLocker lock(fLock); + TRACE("Shutdown(%i)", direction); + T(APICall(this, "shutdown")); + if (direction == SHUT_RD || direction == SHUT_RDWR) fFlags |= FLAG_NO_RECEIVE; @@ -757,6 +794,7 @@ TCPEndpoint::SendData(net_buffer *buffer) TRACE("SendData(buffer %p, size %" B_PRIu32 ", flags %#" B_PRIx32 ") [total %" B_PRIuSIZE " bytes, has %" B_PRIuSIZE "]", buffer, buffer->size, buffer->flags, fSendQueue.Size(), fSendQueue.Free()); + T(APICall(this, "senddata")); uint32 flags = buffer->flags; @@ -856,6 +894,7 @@ TCPEndpoint::SendAvailable() available = EPIPE; TRACE("SendAvailable(): %" B_PRIdSSIZE, available); + T(APICall(this, "sendavailable")); return available; } @@ -876,10 +915,11 @@ TCPEndpoint::FillStat(net_stat *stat) status_t TCPEndpoint::ReadData(size_t numBytes, uint32 flags, net_buffer** _buffer) { + MutexLocker locker(fLock); + TRACE("ReadData(%" B_PRIuSIZE " bytes, flags %#" B_PRIx32 ")", numBytes, flags); - - MutexLocker locker(fLock); + T(APICall(this, "readdata")); *_buffer = NULL; @@ -975,6 +1015,7 @@ TCPEndpoint::ReadAvailable() MutexLocker locker(fLock); TRACE("ReadAvailable(): %" B_PRIdSSIZE, _AvailableData()); + T(APICall(this, "readavailable")); return _AvailableData(); }