How to use the new logging facility?

Last week, logging facility has been added to VMime messaging services. This will allow the developer to trace what is sent and received on the connection between client and server, and may help debugging. We will see in this post how to use this feature, which is supported for IMAP, POP3 and SMTP protocols.

First, you have to create your own tracer, which must implement the vmime::net::tracer interface:

class myTracer : public vmime::net::tracer
{
public:

    myTracer(const vmime::string& proto, const int connectionId)
        : m_proto(proto), m_connectionId(connectionId)
    {
    }

    // Called by VMime to trace what is sent on the socket
    void traceSend(const vmime::string& line)
    {
        std::cout << "[" << m_proto << ":" << m_connectionId
                  << "] C: " << line << std::endl;
    }

    // Called by VMime to trace what is received from the socket
    void traceReceive(const vmime::string& line)
    {
        std::cout << "[" < < m_proto << ":" << m_connectionId
                  << "] S: " << line << std::endl;
    }

private:

    const vmime::string m_proto;
    const int m_connectionId;
};

Also create a factory class, used to instanciate your tracer objects:

class myTracerFactory : public vmime::net::tracerFactory
{
public:

    vmime::shared_ptr <vmime::net::tracer> create
        (vmime::shared_ptr <vmime::net::service> serv,
         const int connectionId)
    {
        return vmime::make_shared <myTracer>
               (serv->getProtocolName(), connectionId);
    }
};

Next, we have to tell VMime to use it. When you create your service (either store or transport), simply call the setTracerFactory on the service and pass an instance of your factory class:

 vmime::shared_ptr <vmime::net::transport> store =
     session->getStore("imaps://user:password@imap.myserver.com");

 // Enable tracing communication between client and server
 store->setTracerFactory(vmime::make_shared <myTracerFactory>());

That’s all! Now, everything which is sent on/received from the socket will be logged using your tracer object. Here is an example of a trace session for IMAP:

[imaps:1] S: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE AUTH=PLAIN] Dovecot ready.
[imaps:1] C: a001 AUTHENTICATE PLAIN
[imaps:1] S: + 
[imaps:1] C: {...SASL exchange: 52 bytes of data...}
[imaps:1] S: a001 OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SPECIAL-USE QUOTA] Logged in
[imaps:1] C: a002 LIST "" ""
[imaps:1] S: * LIST (\Noselect) "." ""
[imaps:1] S: a002 OK List completed.
[imaps:1] C: a003 CAPABILITY
[imaps:1] S: * CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SPECIAL-USE QUOTA
[imaps:1] S: a003 OK Capability completed.
[imaps:1] C: a003 SELECT INBOX (CONDSTORE)
[imaps:1] S: * FLAGS (\Answered \Flagged \Deleted \Seen \Draft $NotJunk NonJunk JunkRecorded $MDNSent NotJunk $Forwarded Junk $Junk Forwarded $MailFlagBit1)
[imaps:1] S: * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft $NotJunk NonJunk JunkRecorded $MDNSent NotJunk $Forwarded Junk $Junk Forwarded $MailFlagBit1 \*)] Flags permitted.
[imaps:1] S: * 104 EXISTS
[imaps:1] S: * 0 RECENT
[imaps:1] S: * OK [UNSEEN 6] First unseen.
[imaps:1] S: * OK [UIDVALIDITY 1268127585] UIDs valid
[imaps:1] S: * OK [UIDNEXT 32716] Predicted next UID
[imaps:1] S: * OK [HIGHESTMODSEQ 148020] Highest
[imaps:1] S: a003 OK [READ-WRITE] Select completed.

Please note that no sensitive data (ie. login or password) will be traced. Same, “blob” data such as message content or SASL exchanges will be logged as a marker which indicates how many bytes were sent/received (eg. “{…SASL exchange: 52 bytes of data…}”).

New feature: simultaneously get and fetch messages

We have released a new feature for IMAP stores: get and fetch messages in a single operation. This will avoid one round-trip to the server.

Let’s say we want to get the flags for the messages UID 2 to 6. Until today, we used to write the following code:

vmime::shared_ptr <vmime::net::folder> f = /* ... */;

vmime::net::messageSet mset(vmime::net::messageSet::byUID(2, 6));

vmime::net::fetchAttributes attribs;
attribs.add(vmime::net::fetchAttributes::FLAGS);

std::vector <vmime::shared_ptr <vmime::net::message> >
    msgs = f->getMessages(mset);

f->fetchMessages(msgs, attribs);

// ...do something with msg[n]->getFlags()...

This resulted into the following IMAP client-server dialog, with two FETCH commands in sequence:

C: a005 UID FETCH 2:6 UID                <-- getMessages()
S: * 1 FETCH (UID 2 MODSEQ (1268172))
S: * 2 FETCH (UID 3 MODSEQ (1268417))
S: * 3 FETCH (UID 4 MODSEQ (1268417))
S: * 4 FETCH (UID 5 MODSEQ (1268312))
S: * 5 FETCH (UID 6 MODSEQ (1268417))
S: a005 OK Success
C: a006 FETCH 1:5 (FLAGS)                <-- fetchMessages()
S: * 1 FETCH (MODSEQ (1268172) FLAGS (NotJunk $NotJunk \Seen))
S: * 2 FETCH (MODSEQ (1268417) FLAGS (NotJunk $NotJunk \Seen))
S: * 3 FETCH (MODSEQ (1268417) FLAGS (NotJunk $NotJunk \Seen))
S: * 4 FETCH (MODSEQ (1268312) FLAGS (NotJunk $NotJunk \Seen))
S: * 5 FETCH (MODSEQ (1268417) FLAGS (NotJunk $NotJunk \Seen))
S: a006 OK Success

With the new getAndFetchMessages() method, we can now write:

vmime::shared_ptr <vmime::net::folder> f = /* ... */;

vmime::net::messageSet mset(vmime::net::messageSet::byUID(2, 6));

vmime::net::fetchAttributes attribs;
attribs.add(vmime::net::fetchAttributes::FLAGS);

std::vector <vmime::shared_ptr <vmime::net::message> >
    msgs = f->getAndFetchMessages(mset, attribs);

// ...do something with msg[n]->getFlags()...

Here is now the dialog between the client and the server:

C: a006 UID FETCH 2:6 (FLAGS UID MODSEQ) 
S: * 1 FETCH (UID 2 MODSEQ (1268172) FLAGS (NotJunk $NotJunk \Seen))
S: * 2 FETCH (UID 3 MODSEQ (1268417) FLAGS (NotJunk $NotJunk \Seen))
S: * 3 FETCH (UID 4 MODSEQ (1268417) FLAGS (NotJunk $NotJunk \Seen))
S: * 4 FETCH (UID 5 MODSEQ (1268312) FLAGS (NotJunk $NotJunk \Seen))
S: * 5 FETCH (UID 6 MODSEQ (1268417) FLAGS (NotJunk $NotJunk \Seen))
S: a006 OK Success

That is, one round-trip to the server saved. Please note that this will work with any fetch attribute, and should also work with any IMAP-compliant server!