[PROTON-1745] [proton-c] PN_CONNECTION_BOUND event is emitted too soon

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: proton-c-0.20.0
• Fix Version/s: proton-c-0.20.0
• Component/s: proton-c
• Labels: regression
• Environment: Fedora 27
• Assignee: Clifford Jansen
• Reporter: Charles E. Rolke
• Created: 17/Jan/18 18:53
• Updated: 26/Mar/18 10:20
• Resolved: 23/Jan/18 17:18

Description

During a PN_CONNECTION_BOUND event proton socket information is not available. At  PN_CONNECTION_REMOTE_OPEN the info is available.

I instrumented an event loop in qpid-dispatch to log the event names as they are delivered and to log the result of creating a qd_connection rhost_port name. The source:

    case PN_CONNECTION_BOUND:
        on_connection_bound(qd_server, e);
        // HACK ALERT
        pn_connection_t *pn_conn = pn_event_connection(e);
        qd_connection_t *qd_conn = pn_connection_get_context(pn_conn);
        set_rhost_port(pn_conn, qd_conn);
        qd_log(qd_server->log_source, QD_LOG_CRITICAL, 
            "At end of connection bound the name is: %s", qd_connection_name(ctx));
        // END HACK ALERT
        break;

    case PN_CONNECTION_REMOTE_OPEN:
        {
        // HACK ALERT
        pn_connection_t *pn_conn = pn_event_connection(e);
        qd_connection_t *qd_conn = pn_connection_get_context(pn_conn);
        set_rhost_port(pn_conn, qd_conn);
        qd_log(qd_server->log_source, QD_LOG_CRITICAL, 
            "At entry to remote open the name is: %s", qd_connection_name(ctx));
        /// END HACK ALERT

 

The log file shows:

2018-01-17 12:38:35.224859 -0500 SERVER (critical) ***** handle sees event: PN_CONNECTION_INIT (/home/chug/git/qpid-dispatch/src/server.c:845)
2018-01-17 12:38:35.224868 -0500 SERVER (critical) ***** handle sees event: PN_CONNECTION_BOUND (/home/chug/git/qpid-dispatch/src/server.c:845)
2018-01-17 12:38:35.224890 -0500 SERVER (critical) At end of connection bound the name is: err: -6 (/home/chug/git/qpid-dispatch/src/server.c:887)

2018-01-17 12:38:35.224965 -0500 SERVER (critical) ***** handle sees event: PN_CONNECTION_REMOTE_OPEN (/home/chug/git/qpid-dispatch/src/server.c:845)
2018-01-17 12:38:35.224971 -0500 SERVER (critical) At entry to remote open the name is: 127.0.0.1:46722 (/home/chug/git/qpid-dispatch/src/server.c:895)

The "err -6" is a snoop on the return result of getnameinfo(): EAI_FAMILY 'ai_family' not supported. I suspect it's because the returned socket is junk.

The code works correctly in 0.19.0, commit fe3c3

Issue Links

• is related to: DISPATCH-912 system_tests_user_id_proxy and system_tests_policy failing