Skip to content

Commit

Permalink
refactor(debug): vastly improve debug messages for framing
Browse files Browse the repository at this point in the history
  • Loading branch information
@mbroadst
mbroadst committed Mar 4, 2016
1 parent e9af405 commit f6c43d9
Show file tree
Hide file tree
Showing 4 changed files with 110 additions and 65 deletions.
33 changes: 19 additions & 14 deletions src/qamqpchannel.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -54,8 54,6 @@ bool QAmqpChannelPrivate::_q_method(const QAmqpMethodFrame &frame)
if (frame.methodClass() != QAmqpFrame::Channel)
return false;

qAmqpDebug("Channel#%d:", channelNumber);

switch (frame.id()) {
case miOpenOk:
openOk(frame);
Expand Down Expand Up @@ -94,8 92,9 @@ void QAmqpChannelPrivate::sendFrame(const QAmqpFrame &frame)

void QAmqpChannelPrivate::resetInternalState()
{
opened = false;
needOpen = true;
if (!opened) return;
opened = false;
needOpen = true;
}

void QAmqpChannelPrivate::open()
Expand All @@ -106,7 105,7 @@ void QAmqpChannelPrivate::open()
if (!client->isConnected())
return;

qAmqpDebug("Open channel #%d", channelNumber);
qAmqpDebug("<- channel#open( channel=%d )", channelNumber);
QAmqpMethodFrame frame(QAmqpFrame::Channel, miOpen);
frame.setChannel(channelNumber);

Expand Down Expand Up @@ -136,17 135,19 @@ void QAmqpChannelPrivate::flow(bool active)
void QAmqpChannelPrivate::flow(const QAmqpMethodFrame &frame)
{
Q_UNUSED(frame);
qAmqpDebug() << Q_FUNC_INFO;
qAmqpDebug("-> channel#flow( channel=%d )", channelNumber);
}

void QAmqpChannelPrivate::flowOk()
{
qAmqpDebug() << Q_FUNC_INFO;
qAmqpDebug("<- channel#flowOk( channel=%d )", channelNumber);
}

void QAmqpChannelPrivate::flowOk(const QAmqpMethodFrame &frame)
{
Q_Q(QAmqpChannel);
qAmqpDebug("-> channel#flowOk( channel=%d )", channelNumber);

QByteArray data = frame.arguments();
QDataStream stream(&data, QIODevice::ReadOnly);
bool active = QAmqpFrame::readAmqpField(stream, QAmqpMetaType::Boolean).toBool();
Expand All @@ -158,6 159,9 @@ void QAmqpChannelPrivate::flowOk(const QAmqpMethodFrame &frame)

void QAmqpChannelPrivate::close(int code, const QString &text, int classId, int methodId)
{
qAmqpDebug("<- channel#close( channel=%d, reply-code=%d, text=%s class-id=%d, method-id:%d, )",
channelNumber, code, qPrintable(text), classId, methodId);

QByteArray arguments;
QDataStream stream(&arguments, QIODevice::WriteOnly);

Expand All @@ -181,7 185,6 @@ void QAmqpChannelPrivate::close(int code, const QString &text, int classId, int
void QAmqpChannelPrivate::close(const QAmqpMethodFrame &frame)
{
Q_Q(QAmqpChannel);
qAmqpDebug(">> CLOSE");
QByteArray data = frame.arguments();
QDataStream stream(&data, QIODevice::ReadOnly);
qint16 code = 0, classId, methodId;
Expand All @@ -199,11 202,8 @@ void QAmqpChannelPrivate::close(const QAmqpMethodFrame &frame)
Q_EMIT q->error(error);
}

qAmqpDebug(">> code: %d", code);
qAmqpDebug(">> text: %s", qPrintable(text));
qAmqpDebug(">> class-id: %d", classId);
qAmqpDebug(">> method-id: %d", methodId);
Q_EMIT q->closed();
qAmqpDebug("-> channel#close( channel=%d, reply-code=%d, reply-text=%s, class-id=%d, method-id=%d, )",
channelNumber, code, qPrintable(text), classId, methodId);

// complete handshake
QAmqpMethodFrame closeOkFrame(QAmqpFrame::Channel, miCloseOk);
Expand All @@ -216,6 216,7 @@ void QAmqpChannelPrivate::close(const QAmqpMethodFrame &frame)

void QAmqpChannelPrivate::closeOk(const QAmqpMethodFrame &)
{
qAmqpDebug("-> channel#closeOk( channel=%d )", channelNumber);
notifyClosed();
}

Expand All @@ -230,7 231,7 @@ void QAmqpChannelPrivate::notifyClosed()
void QAmqpChannelPrivate::openOk(const QAmqpMethodFrame &)
{
Q_Q(QAmqpChannel);
qAmqpDebug(">> OpenOK");
qAmqpDebug("-> channel#openOk( channel=%d )", channelNumber);
opened = true;
Q_EMIT q->opened();
q->channelOpened();
Expand All @@ -246,6 247,7 @@ void QAmqpChannelPrivate::qosOk(const QAmqpMethodFrame &frame)
{
Q_Q(QAmqpChannel);
Q_UNUSED(frame)
qAmqpDebug("-> basic#qosOk( channel=%d )", channelNumber);

prefetchCount = requestedPrefetchCount;
prefetchSize = requestedPrefetchSize;
Expand Down Expand Up @@ -320,6 322,9 @@ void QAmqpChannel::qos(qint16 prefetchCount, qint32 prefetchSize)
stream << qint16(prefetchCount);
stream << qint8(0x0); // global

qAmqpDebug("<- basic#qos( channel=%d, prefetch-size=%d, prefetch-count=%d, global=%d )",
d->channelNumber, prefetchSize, prefetchCount, 0);

frame.setArguments(arguments);
d->sendFrame(frame);
}
Expand Down
55 changes: 25 additions & 30 deletions src/qamqpclient.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -171,10 171,9 @@ void QAmqpClientPrivate::_q_socketDisconnected()
Q_Q(QAmqpClient);
buffer.clear();
resetChannelState();
if (connected) {
if (connected)
connected = false;
Q_EMIT q->disconnected();
}
Q_EMIT q->disconnected();
}

void QAmqpClientPrivate::_q_heartbeat()
Expand Down Expand Up @@ -336,7 335,6 @@ bool QAmqpClientPrivate::_q_method(const QAmqpMethodFrame &frame)
if (frame.methodClass() != QAmqpFrame::Connection)
return false;

qAmqpDebug() << "Connection:";
if (closed) {
if (frame.id() == QAmqpClientPrivate::miCloseOk)
closeOk(frame);
Expand Down Expand Up @@ -372,7 370,6 @@ bool QAmqpClientPrivate::_q_method(const QAmqpMethodFrame &frame)
void QAmqpClientPrivate::start(const QAmqpMethodFrame &frame)
{
Q_Q(QAmqpClient);
qAmqpDebug(">> Start");
QByteArray data = frame.arguments();
QDataStream stream(&data, QIODevice::ReadOnly);

Expand All @@ -387,18 384,11 @@ void QAmqpClientPrivate::start(const QAmqpMethodFrame &frame)
QAmqpFrame::readAmqpField(stream, QAmqpMetaType::LongString).toString().split(' ');
QString locales = QAmqpFrame::readAmqpField(stream, QAmqpMetaType::LongString).toString();

qAmqpDebug(">> version_major: %d", version_major);
qAmqpDebug(">> version_minor: %d", version_minor);

// NOTE: replace with qDebug overload
// QAmqpFrame::print(table);

qAmqpDebug() << ">> mechanisms: " << mechanisms;
qAmqpDebug(">> locales: %s", qPrintable(locales));
qAmqpDebug("-> connection#start( version_major=%d, version_minor=%d, mechanisms=(%s), locales=%s",
version_major, version_minor, qPrintable(mechanisms.join(',')), qPrintable(locales));

if (!mechanisms.contains(authenticator->type())) {
socket->disconnectFromHost();
Q_EMIT q->disconnected();
return;
}

Expand All @@ -408,12 398,11 @@ void QAmqpClientPrivate::start(const QAmqpMethodFrame &frame)
void QAmqpClientPrivate::secure(const QAmqpMethodFrame &frame)
{
Q_UNUSED(frame)
qAmqpDebug() << Q_FUNC_INFO << "called!";
qAmqpDebug("-> connection#secure()");
}

void QAmqpClientPrivate::tune(const QAmqpMethodFrame &frame)
{
qAmqpDebug(">> Tune");
QByteArray data = frame.arguments();
QDataStream stream(&data, QIODevice::ReadOnly);

Expand All @@ -430,9 419,8 @@ void QAmqpClientPrivate::tune(const QAmqpMethodFrame &frame)
channelMax = !channelMax ? channel_max : qMax(channel_max, channelMax);
heartbeatDelay = !heartbeatDelay ? heartbeat_delay: heartbeatDelay;

qAmqpDebug(">> channel_max: %d", channelMax);
qAmqpDebug(">> frame_max: %d", frameMax);
qAmqpDebug(">> heartbeat: %d", heartbeatDelay);
qAmqpDebug("-> connection#tune( channel_max=%d, frame_max=%d, heartbeat=%d )",
channelMax, frameMax, heartbeatDelay);

if (heartbeatTimer) {
heartbeatTimer->setInterval(heartbeatDelay * 1000);
Expand All @@ -450,27 438,25 @@ void QAmqpClientPrivate::openOk(const QAmqpMethodFrame &frame)
{
Q_Q(QAmqpClient);
Q_UNUSED(frame)
qAmqpDebug(">> OpenOK");
qAmqpDebug("-> connection#openOk()");
connected = true;
Q_EMIT q->connected();
}

void QAmqpClientPrivate::closeOk(const QAmqpMethodFrame &frame)
{
Q_Q(QAmqpClient);
Q_UNUSED(frame)
qAmqpDebug() << Q_FUNC_INFO << "received";
qAmqpDebug("-> connection#closeOk()");

connected = false;
if (heartbeatTimer)
heartbeatTimer->stop();
socket->disconnectFromHost();
Q_EMIT q->disconnected();
}

void QAmqpClientPrivate::close(const QAmqpMethodFrame &frame)
{
Q_Q(QAmqpClient);
qAmqpDebug(">> CLOSE");
QByteArray data = frame.arguments();
QDataStream stream(&data, QIODevice::ReadOnly);
qint16 code = 0, classId, methodId;
Expand All @@ -479,10 465,8 @@ void QAmqpClientPrivate::close(const QAmqpMethodFrame &frame)
stream >> classId;
stream >> methodId;

qAmqpDebug(">> code: %d", code);
qAmqpDebug(">> text: %s", qPrintable(text));
qAmqpDebug(">> class-id: %d", classId);
qAmqpDebug(">> method-id: %d", methodId);
qAmqpDebug("-> connection#close( reply-code=%d, reply-text=%s, class-id=%d, method-id:%d )",
code, qPrintable(text), classId, methodId);

QAMQP::Error checkError = static_cast<QAMQP::Error>(code);
if (checkError != QAMQP::NoError) {
Expand All @@ -507,6 491,7 @@ void QAmqpClientPrivate::close(const QAmqpMethodFrame &frame)

// complete handshake
QAmqpMethodFrame closeOkFrame(QAmqpFrame::Connection, QAmqpClientPrivate::miCloseOk);
qAmqpDebug("<- connection#closeOk()");
sendFrame(closeOkFrame);
}

Expand All @@ -525,14 510,15 @@ void QAmqpClientPrivate::startOk()

authenticator->write(stream);
QAmqpFrame::writeAmqpField(stream, QAmqpMetaType::ShortString, QLatin1String("en_US"));

frame.setArguments(arguments);

qAmqpDebug("<- connection#startOk()"); // @todo: fill this out
sendFrame(frame);
}

void QAmqpClientPrivate::secureOk()
{
qAmqpDebug() << Q_FUNC_INFO;
qAmqpDebug("-> connection#secureOk()");
}

void QAmqpClientPrivate::tuneOk()
Expand All @@ -545,6 531,9 @@ void QAmqpClientPrivate::tuneOk()
stream << qint32(frameMax);
stream << qint16(heartbeatDelay);

qAmqpDebug("<- connection#tuneOk( channelMax=%d, frameMax=%d, heartbeatDelay=%d",
channelMax, frameMax, heartbeatDelay);

frame.setArguments(arguments);
sendFrame(frame);
}
Expand All @@ -560,6 549,9 @@ void QAmqpClientPrivate::open()
stream << qint8(0);
stream << qint8(0);

qAmqpDebug("<- connection#open( virtualHost=%s, reserved-1=%d, reserved-2=%d",
qPrintable(virtualHost), 0, 0);

frame.setArguments(arguments);
sendFrame(frame);
}
Expand All @@ -573,6 565,9 @@ void QAmqpClientPrivate::close(int code, const QString &text, int classId, int m
stream << qint16(classId);
stream << qint16(methodId);

qAmqpDebug("<- connection#close( reply-code=%d, reply-text=%s, class-id=%d, method-id:%d )",
code, qPrintable(text), classId, methodId);

QAmqpMethodFrame frame(QAmqpFrame::Connection, QAmqpClientPrivate::miClose);
frame.setArguments(arguments);
sendFrame(frame);
Expand Down
26 changes: 17 additions & 9 deletions src/qamqpexchange.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -62,6 62,11 @@ void QAmqpExchangePrivate::declare()
stream << qint8(options);
QAmqpFrame::writeAmqpField(stream, QAmqpMetaType::Hash, arguments);

qAmqpDebug("<- exchange#declare( name=%s, type=%s, passive=%d, durable=%d, no-wait=%d )",
qPrintable(name), qPrintable(type),
options.testFlag(QAmqpExchange::Passive), options.testFlag(QAmqpExchange::Durable),
options.testFlag(QAmqpExchange::NoWait));

frame.setArguments(args);
sendFrame(frame);
delayedDeclare = false;
Expand Down Expand Up @@ -113,27 118,25 @@ bool QAmqpExchangePrivate::_q_method(const QAmqpMethodFrame &frame)
void QAmqpExchangePrivate::declareOk(const QAmqpMethodFrame &frame)
{
Q_UNUSED(frame)

Q_Q(QAmqpExchange);
qAmqpDebug() << "declared exchange: " << name;
qAmqpDebug("-> exchange[ %s ]#declareOk()", qPrintable(name));
declared = true;
Q_EMIT q->declared();
}

void QAmqpExchangePrivate::deleteOk(const QAmqpMethodFrame &frame)
{
Q_UNUSED(frame)

Q_Q(QAmqpExchange);
qAmqpDebug() << "deleted exchange: " << name;
qAmqpDebug("-> exchange#deleteOk[ %s ]()", qPrintable(name));
declared = false;
Q_EMIT q->removed();
}

void QAmqpExchangePrivate::_q_disconnected()
{
QAmqpChannelPrivate::_q_disconnected();
qAmqpDebug() << "exchange " << name << " disconnected";
qAmqpDebug() << "exchange disconnected: " << name;
delayedDeclare = false;
declared = false;
unconfirmedDeliveryTags.clear();
Expand All @@ -158,10 161,8 @@ void QAmqpExchangePrivate::basicReturn(const QAmqpMethodFrame &frame)
Q_EMIT q->error(error);
}

qAmqpDebug(">> replyCode: %d", replyCode);
qAmqpDebug(">> replyText: %s", qPrintable(replyText));
qAmqpDebug(">> exchangeName: %s", qPrintable(exchangeName));
qAmqpDebug(">> routingKey: %s", qPrintable(routingKey));
qAmqpDebug("-> basic#return( reply-code=%d, reply-text=%s, exchange=%s, routing-key=%s )",
replyCode, qPrintable(replyText), qPrintable(exchangeName), qPrintable(routingKey));
}

void QAmqpExchangePrivate::handleAckOrNack(const QAmqpMethodFrame &frame)
Expand Down Expand Up @@ -266,6 267,9 @@ void QAmqpExchange::remove(int options)
QAmqpFrame::writeAmqpField(stream, QAmqpMetaType::ShortString, d->name);
stream << qint8(options);

qAmqpDebug("<- exchange#delete( exchange=%s, if-unused=%d, no-wait=%d )",
qPrintable(d->name), options & QAmqpExchange::roIfUnused, options & QAmqpExchange::roNoWait);

frame.setArguments(arguments);
d->sendFrame(frame);
}
Expand Down Expand Up @@ -305,6 309,10 @@ void QAmqpExchange::publish(const QByteArray &message, const QString &routingKey
QAmqpFrame::writeAmqpField(out, QAmqpMetaType::ShortString, routingKey);
out << qint8(publishOptions);

qAmqpDebug("<- basic#publish( exchange=%s, routing-key=%s, mandatory=%d, immediate=%d )",
qPrintable(d->name), qPrintable(routingKey),
publishOptions & QAmqpExchange::poMandatory, publishOptions & QAmqpExchange::poImmediate);

frame.setArguments(arguments);
d->sendFrame(frame);

Expand Down
Loading

0 comments on commit f6c43d9

Please sign in to comment.