Attachment 57387 Details for Bug 46391 – log for a failing run of file-transfer/metadata.py

log for a failing run of file-transfer/metadata.py

salut-testing.log (text/plain), 95.43 KB, created by Will Thompson on 2012-02-21 04:51:29 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Will Thompson

Created: 2012-02-21 04:51:29 UTC

Size: 95.43 KB

patch

obsolete

>(process:17598): tp-glib/proxy-DEBUG: tp_proxy_dispose: 0xb45000
>(process:17598): tp-glib/proxy-DEBUG: tp_proxy_invalidate: 0xb45000: Proxy unreferenced
>(process:17598): tp-glib/proxy-DEBUG: tp_proxy_finalize: 0xb45000
>(process:17598): salut-DEBUG: salut_plugin_loader_probe: probing /home/wjt/src/tp/salut/plugins/.libs
>** (process:17598): DEBUG: test_plugin_init: 0xb25420
>(process:17598): tp-glib/proxy-DEBUG: tp_proxy_dispose: 0xb45090
>(process:17598): tp-glib/proxy-DEBUG: tp_proxy_invalidate: 0xb45090: Proxy unreferenced
>(process:17598): tp-glib/proxy-DEBUG: tp_proxy_finalize: 0xb45090
>(process:17598): salut-DEBUG: plugin_loader_try_to_load: loaded 'Salut test plugin' version 0.7.1 (/home/wjt/src/tp/salut/plugins/.libs/test.so), implementing these sidecars: (org.freedesktop.Telepathy.Salut.Plugin.Test)
>** (telepathy-salut:17598): DEBUG: initialize: 0xb25420 on connection manager 0xb48020
>(telepathy-salut:17598): tp-glib-DEBUG: started version 0.7.1 (telepathy-glib version 0.17.5)
>(telepathy-salut:17598): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for nickname: "avahi/file-transfer/metadata.py"
>(telepathy-salut:17598): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for first-name: "test"
>(telepathy-salut:17598): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for last-name: "suite"
>(telepathy-salut:17598): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for published-name: "testsuite"
>(telepathy-salut:17598): tp-glib/presence-DEBUG: tp_presence_mixin_class_init: called.
>(telepathy-salut:17598): salut-DEBUG: gabble_capabilities_init: 0xb63020
>(telepathy-salut:17598): tp-glib/presence-DEBUG: tp_presence_mixin_init: called.
>** (telepathy-salut:17598): DEBUG: create_channel_managers: 0xb25420 on connection 0xb63020
>(telepathy-salut:17598): tp-glib/connection-DEBUG: tp_base_connection_register: 0xb63020: bus name org.freedesktop.Telepathy.Connection.salut.local_xmpp.testsuite; object path /org/freedesktop/Telepathy/Connection/salut/local_xmpp/testsuite
>(telepathy-salut:17598): wocky-DEBUG: wocky_meta_porter_start: wocky-meta-porter.c:1169: listening on port 5298
>(telepathy-salut:17598): salut-DEBUG: salut_presence_cache_learn_caps: learning http://telepathy.freedesktop.org/caps#pmAwMK9hWdMMhgygNcUKoydJxpY=
>
>(telepathy-salut:17598): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 4294967295, now 1, for reason 1
>(telepathy-salut:17598): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 1, for reason 1
>(telepathy-salut:17598): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams'>
>
>(telepathy-salut:17598): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17598): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17598): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17598): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17598): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 1, now 0, for reason 0
>(telepathy-salut:17598): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 0, for reason 0
>(telepathy-salut:17598): salut-DEBUG: sidecars_conn_status_changed_cb: connected; requesting sidecars from plugins
>(telepathy-salut:17598): salut-DEBUG: salut_contact_manager_all_for_now_cb: Contact list received
>tp_group_mixin_change_flags: emitting group flags changed
>  added    : [PROPERTIES]
>  removed  : []
>  flags now: [PROPERTIES|MEMBERS_CHANGED_DETAILED]
>(telepathy-salut:17598): tp-glib/groups-DEBUG: tp_group_mixin_change_flags: No change: 6144 includes all the bits of 0 and none of 0
>tp_group_mixin_change_flags: emitting group flags changed
>  added    : [PROPERTIES]
>  removed  : []
>  flags now: [PROPERTIES|MEMBERS_CHANGED_DETAILED]
>(telepathy-salut:17598): tp-glib/groups-DEBUG: tp_group_mixin_change_flags: No change: 6144 includes all the bits of 0 and none of 0
>(telepathy-salut:17598): tp-glib/contact-lists-DEBUG: tp_base_contact_list_set_list_received: Initial contacts: 
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): salut-DEBUG: salut_contact_manager_contact_created: Adding testsuite@testsuite to contacts
>(telepathy-salut:17598): salut-DEBUG: salut_avahi_contact_add_service: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 0): added
>(telepathy-salut:17598): wocky-DEBUG: Parsing chunk: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='j
>(telepathy-salut:17598): salut-DEBUG: salut_avahi_contact_add_service: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 1): added
>(telepathy-salut:17598): wocky-DEBUG: Parsing chunk: abber:client' xmlns:stream='http://etherx.jabber.org/streams'>
>
>(telepathy-salut:17598): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17598): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17598): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'testsuite@testsuite' refcount 0 --> 1
>(telepathy-salut:17598): salut-DEBUG: contact_resolved_cb: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 0): contact testsuite@testsuite resolved
>(telepathy-salut:17598): salut-DEBUG: salut_presence_cache_process_caps: Called for testsuite@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/caps' 'pmAwMK9hWdMMhgygNcUKoydJxpY='
>(telepathy-salut:17598): salut-DEBUG: salut_presence_cache_change_caps: setting caps for testsuite@testsuite (thanks to an existing cache entry)
>(telepathy-salut:17598): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: Contact testsuite@testsuite: subscribe=Y publish=Y ''
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [1 (testsuite@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [1 (testsuite@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([1 changed], [0 removed])
>(telepathy-salut:17598): salut-DEBUG: contact_change_cb: Emitting contact changes for testsuite@testsuite: 255
>(telepathy-salut:17598): salut-DEBUG: _contact_manager_contact_alias_changed: Emitting AliasesChanged
>(telepathy-salut:17598): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17598): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17598): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17598): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17598): salut-DEBUG: contact_resolved_cb: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 1): contact testsuite@testsuite resolved
>(telepathy-salut:17598): salut-DEBUG: salut_presence_cache_process_caps: Called for testsuite@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/caps' 'pmAwMK9hWdMMhgygNcUKoydJxpY='
>(telepathy-salut:17598): salut-DEBUG: salut_presence_cache_change_caps: capabilities of testsuite@testsuite did not actually change
>(telepathy-salut:17598): salut-DEBUG: salut_contact_manager_contact_created: Adding test-ft-metadata@testsuite to contacts
>(telepathy-salut:17598): salut-DEBUG: salut_avahi_contact_add_service: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): added
>(telepathy-salut:17598): salut-DEBUG: contact_resolved_cb: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): contact test-ft-metadata@testsuite resolved
>(telepathy-salut:17598): salut-DEBUG: salut_presence_cache_process_caps: Called for test-ft-metadata@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/fake-client' 'XDbFaoNtLjsD1Rm5XCLnF586udM='
>(telepathy-salut:17598): salut-DEBUG: disco_waiter_new: created waiter 0xb98260 for contact test-ft-metadata@testsuite
>(telepathy-salut:17598): salut-DEBUG: salut_disco_request: Creating disco request 0xb3d600 for test-ft-metadata@testsuite
>(telepathy-salut:17598): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'test-ft-metadata@testsuite' refcount 0 --> 1
>(telepathy-salut:17598): wocky-DEBUG: process_one_address: wocky-ll-connection-factory.c:190: connecting to 127.0.0.1 (port 34415)
>(telepathy-salut:17598): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: Contact test-ft-metadata@testsuite: subscribe=Y publish=Y ''
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [2 (test-ft-metadata@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 2
>  reason        : 0: unspecified reason
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [2 (test-ft-metadata@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17598): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([1 changed], [0 removed])
>(telepathy-salut:17598): salut-DEBUG: contact_change_cb: Emitting contact changes for test-ft-metadata@testsuite: 255
>(telepathy-salut:17598): salut-DEBUG: _contact_manager_contact_alias_changed: Emitting AliasesChanged
>(telepathy-salut:17598): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17598): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17598): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17598): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17598): wocky-DEBUG: connect_to_host_cb: wocky-ll-connection-factory.c:151: made connection
>(telepathy-salut:17598): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' to="test-ft-metadata@testsuite" from="testsuite@testsuite" version="1.0">
>
>(telepathy-salut:17598): wocky-DEBUG: send_open_cb: wocky-ll-connector.c:408: successfully sent stream open, now waiting for other side to too
>(telepathy-salut:17598): tp-glib/connection-DEBUG: channel_request_new: New channel request at 0xba1d50: ctype=org.freedesktop.Telepathy.Channel.Type.ContactList htype=3 handle=2 suppress=0
>(telepathy-salut:17598): tp-glib/connection-DEBUG: satisfy_request: completing queued request 0xba1d50 with success, channel_type=org.freedesktop.Telepathy.Channel.Type.ContactList, handle_type=3, handle=2, suppress_handler=0
>(telepathy-salut:17598): tp-glib/connection-DEBUG: channel_request_free: Freeing channel request at 0xba1d50: ctype=org.freedesktop.Telepathy.Channel.Type.ContactList htype=3 handle=2 suppress=0
>(telepathy-salut:17598): wocky-DEBUG: Parsing chunk: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='testsuite@testsuite' version='1.0' from='test-ft-metadata@testsuite'><stream:features xmlns:stream='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'/>
>(telepathy-salut:17598): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17598): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: to = 'testsuite@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17598): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: version = '1.0' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17598): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: from = 'test-ft-metadata@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17598): wocky-DEBUG: _end_element_ns: Received stanza
>* features xmlns='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'
>(telepathy-salut:17598): wocky-DEBUG: recv_open_cb: wocky-ll-connector.c:361: connected, sending stream features but not expecting anything back
>(telepathy-salut:17598): wocky-DEBUG: _write_node_tree: Serializing tree:
>* features xmlns='http://etherx.jabber.org/streams'
>(telepathy-salut:17598): wocky-DEBUG: Writing xml: <stream:features/>
>(telepathy-salut:17598): wocky-DEBUG: made_connection_connect_cb: wocky-meta-porter.c:953: connected
>(telepathy-salut:17598): wocky-DEBUG: _write_node_tree: Serializing tree:
>* iq xmlns='jabber:client' type='get' to='test-ft-metadata@testsuite' from='testsuite@testsuite' id='131652656981'
>    * query xmlns='http://jabber.org/protocol/disco#info' node='http://telepathy.freedesktop.org/fake-client#XDbFaoNtLjsD1Rm5XCLnF586udM='
>(telepathy-salut:17598): wocky-DEBUG: Writing xml: <iq type="get" to="test-ft-metadata@testsuite" from="testsuite@testsuite" id="131652656981"><query node="http://telepathy.freedesktop.org/fake-client#XDbFaoNtLjsD1Rm5XCLnF586udM=" xmlns="http://jabber.org/protocol/disco#info"/></iq>
>(telepathy-salut:17598): wocky-DEBUG: wocky_ll_connector_dispose: wocky-ll-connector.c:152: dispose called
>(telepathy-salut:17598): wocky-DEBUG: handle_stanza: wocky-c2s-porter.c:1023: Stanza not handled
>(telepathy-salut:17598): wocky-DEBUG: Parsing chunk: <iq xmlns='jabber:client' from='test-ft-metadata@testsuite' type='result' id='131652656981' to='testsuite@testsuite'><query xmlns='http://jabber.org/protocol/disco#info'><feature var='jabber:iq:oob'/><feature var='http://telepathy.freedesktop.org/xmpp/file-transfer-metadata'/></query></iq></stream:stream>
>(telepathy-salut:17598): wocky-DEBUG: _end_element_ns: Received stanza
>* iq xmlns='jabber:client' from='test-ft-metadata@testsuite' type='result' id='131652656981' to='testsuite@testsuite'
>    * query xmlns='http://jabber.org/protocol/disco#info'
>        * feature var='jabber:iq:oob'
>        * feature var='http://telepathy.freedesktop.org/xmpp/file-transfer-metadata'
>(telepathy-salut:17598): wocky-DEBUG: _end_element_ns: wocky-xmpp-reader.c:602: Stream ended
>(telepathy-salut:17598): salut-DEBUG: salut_presence_cache_change_caps: setting caps for test-ft-metadata@testsuite (thanks to test-ft-metadata@testsuite)
>(telepathy-salut:17598): salut-DEBUG: salut_contact_manager_get_contact: Getting contact for: test-ft-metadata@testsuite
>(telepathy-salut:17598): salut-DEBUG: disco_waiter_free: freeing waiter 0xb98260 for contact test-ft-metadata@testsuite
>(telepathy-salut:17598): salut-DEBUG: disco_waiter_list_free: list (nil)
>(telepathy-salut:17598): wocky-DEBUG: wocky_meta_porter_unhold: wocky-meta-porter.c:426: Porter to 'test-ft-metadata@testsuite' refcount 1 --> 0
>(telepathy-salut:17598): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17598): wocky-DEBUG: stanza_received_cb: wocky-c2s-porter.c:1294: Error receiving stanza: Connection has been closed for reading stanzas
>(telepathy-salut:17598): wocky-DEBUG: porter_remote_error_cb: wocky-meta-porter.c:254: remote error in porter, close it
>(telepathy-salut:17598): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'test-ft-metadata@testsuite' closing, remove it from our records
>(telepathy-salut:17598): wocky-DEBUG: wocky_c2s_porter_force_close_async: wocky-c2s-porter.c:2053: remote is already closed, close the XMPP connection
>(telepathy-salut:17598): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'test-ft-metadata@testsuite' closing, remove it from our records
>(telepathy-salut:17598): wocky-DEBUG: connection_force_close_cb: wocky-c2s-porter.c:1266: XMPP connection has been closed; complete the force close operation
>(telepathy-salut:17598): wocky-DEBUG: wocky_c2s_porter_finalize: wocky-c2s-porter.c:568: finalize porter 0xb94190
>(telepathy-salut:17598): tp-glib/connection-DEBUG: channel_request_new: New channel request at 0xba3180: ctype=org.freedesktop.Telepathy.Channel.Type.FileTransfer htype=1 handle=2 suppress=1
>(telepathy-salut:17598): salut-DEBUG: salut_ft_manager_handle_request: File transfer request
>(telepathy-salut:17598): salut-DEBUG: salut_contact_manager_get_contact: Getting contact for: test-ft-metadata@testsuite
>(telepathy-salut:17598): salut-DEBUG: salut_ft_manager_handle_request: Requested outgoing channel with contact: test-ft-metadata@testsuite
>(telepathy-salut:17598): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'test-ft-metadata@testsuite' refcount 0 --> 1
>(telepathy-salut:17598): salut-DEBUG: salut_file_transfer_channel_constructor: New FT channel created: /org/freedesktop/Telepathy/Connection/salut/local_xmpp/testsuite/FileTransferChannel/0xb51900 (contact: test-ft-metadata@testsuite, initiator: testsuite@testsuite, file: "The foo.txt", size: 16)
>(telepathy-salut:17598): salut-DEBUG: salut_file_transfer_channel_offer_file: Offering file transfer
>(telepathy-salut:17598): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'test-ft-metadata@testsuite' refcount 1 --> 2
>(telepathy-salut:17598): wocky-DEBUG: process_one_address: wocky-ll-connection-factory.c:190: connecting to 127.0.0.1 (port 34415)
>(telepathy-salut:17598): tp-glib/connection-DEBUG: satisfy_request: completing queued request 0xba3180 with success, channel_type=org.freedesktop.Telepathy.Channel.Type.FileTransfer, handle_type=1, handle=2, suppress_handler=1
>(telepathy-salut:17598): tp-glib/connection-DEBUG: channel_request_free: Freeing channel request at 0xba3180: ctype=org.freedesktop.Telepathy.Channel.Type.FileTransfer htype=1 handle=2 suppress=1
>(telepathy-salut:17598): wocky-DEBUG: connect_to_host_cb: wocky-ll-connection-factory.c:151: made connection
>(telepathy-salut:17598): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' to="test-ft-metadata@testsuite" from="testsuite@testsuite" version="1.0">
>
>(telepathy-salut:17598): wocky-DEBUG: send_open_cb: wocky-ll-connector.c:408: successfully sent stream open, now waiting for other side to too
>(telepathy-salut:17598): wocky-DEBUG: Parsing chunk: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='testsuite@testsuite' version='1.0' from='test-ft-metadata@testsuite'><stream:features xmlns:stream='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'/>
>(telepathy-salut:17598): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17598): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: to = 'testsuite@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17598): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: version = '1.0' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17598): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: from = 'test-ft-metadata@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17598): wocky-DEBUG: _end_element_ns: Received stanza
>* features xmlns='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'
>(telepathy-salut:17598): wocky-DEBUG: recv_open_cb: wocky-ll-connector.c:361: connected, sending stream features but not expecting anything back
>(telepathy-salut:17598): wocky-DEBUG: _write_node_tree: Serializing tree:
>* features xmlns='http://etherx.jabber.org/streams'
>(telepathy-salut:17598): wocky-DEBUG: Writing xml: <stream:features/>
>(telepathy-salut:17598): wocky-DEBUG: made_connection_connect_cb: wocky-meta-porter.c:953: connected
>(telepathy-salut:17598): wocky-DEBUG: _write_node_tree: Serializing tree:
>* iq xmlns='jabber:client' type='set' from='testsuite@testsuite' to='test-ft-metadata@testsuite' id='gibber-file-transfer-0'
>    * query xmlns='jabber:iq:oob'
>        * url type='file' mimeType='text/plain' size='16'
>            "http://127.0.0.1:41543/gibber-file-transfer-0/The%20foo.txt"
>        * desc
>            "A nice file to test"
>(telepathy-salut:17598): wocky-DEBUG: Writing xml: <iq type="set" from="testsuite@testsuite" to="test-ft-metadata@testsuite" id="gibber-file-transfer-0"><query xmlns="jabber:iq:oob"><url type="file" mimeType="text/plain" size="16">http://127.0.0.1:41543/gibber-file-transfer-0/The%20foo.txt</url><desc>A nice file to test</desc></query></iq>
>(telepathy-salut:17598): wocky-DEBUG: wocky_meta_porter_unhold: wocky-meta-porter.c:426: Porter to 'test-ft-metadata@testsuite' refcount 2 --> 1
>(telepathy-salut:17598): wocky-DEBUG: wocky_ll_connector_dispose: wocky-ll-connector.c:152: dispose called
>(telepathy-salut:17598): wocky-DEBUG: handle_stanza: wocky-c2s-porter.c:1023: Stanza not handled
>(telepathy-salut:17598): salut-DEBUG: get_socket_channel: local socket /tmp/tp-ft-953849726
>** (telepathy-salut:17598): DEBUG: http_server_cb: Serving '/gibber-file-transfer-0/The foo.txt'
>(telepathy-salut:17598): salut-DEBUG: accept_local_socket_connection: Client connected to local socket
>** (telepathy-salut:17598): DEBUG: gibber_oob_file_transfer_send: Starting HTTP chunked file transfer
>** (telepathy-salut:17598): DEBUG: http_server_wrote_chunk_cb: Chunk written, adding a watch to get more input (not cancelled)
>** (telepathy-salut:17598): DEBUG: input_channel_readable_cb: Data available, writing a 16 bytes chunk
>** (telepathy-salut:17598): DEBUG: http_server_wrote_chunk_cb: Chunk written, adding a watch to get more input (not cancelled)
>(telepathy-salut:17598): wocky-DEBUG: Parsing chunk: <iq to='testsuite@testsuite' from='test-ft-metadata@testsuite' id='gibber-file-transfer-0' type='result'/>
>(telepathy-salut:17598): wocky-DEBUG: _end_element_ns: Received stanza
>* iq xmlns='jabber:client' to='testsuite@testsuite' from='test-ft-metadata@testsuite' id='gibber-file-transfer-0' type='result'
>(telepathy-salut:17598): wocky-DEBUG: handle_iq_reply: wocky-c2s-porter.c:907: Ignored IQ reply
>(telepathy-salut:17598): wocky-DEBUG: wocky_meta_porter_unhold: wocky-meta-porter.c:426: Porter to 'test-ft-metadata@testsuite' refcount 1 --> 0
>(telepathy-salut:17598): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>** (telepathy-salut:17598): DEBUG: input_channel_readable_cb: EOF received on input
>** (telepathy-salut:17598): DEBUG: input_channel_readable_cb: Closing HTTP chunked transfer
>(telepathy-salut:17598): salut-DEBUG: salut_file_transfer_channel_do_close: Emitting closed signal for /org/freedesktop/Telepathy/Connection/salut/local_xmpp/testsuite/FileTransferChannel/0xb51900
>(telepathy-salut:17598): salut-DEBUG: file_channel_closed: Removing channel with handle 2
>
>GLib-GObject-WARNING **: instance of invalid non-instantiatable type `(null)'
>(process:17620): tp-glib/proxy-DEBUG: tp_proxy_dispose: 0xada000
>(process:17620): tp-glib/proxy-DEBUG: tp_proxy_invalidate: 0xada000: Proxy unreferenced
>(process:17620): tp-glib/proxy-DEBUG: tp_proxy_finalize: 0xada000
>(process:17620): salut-DEBUG: salut_plugin_loader_probe: probing /home/wjt/src/tp/salut/plugins/.libs
>** (process:17620): DEBUG: test_plugin_init: 0xaba420
>(process:17620): tp-glib/proxy-DEBUG: tp_proxy_dispose: 0xada090
>(process:17620): tp-glib/proxy-DEBUG: tp_proxy_invalidate: 0xada090: Proxy unreferenced
>(process:17620): tp-glib/proxy-DEBUG: tp_proxy_finalize: 0xada090
>(process:17620): salut-DEBUG: plugin_loader_try_to_load: loaded 'Salut test plugin' version 0.7.1 (/home/wjt/src/tp/salut/plugins/.libs/test.so), implementing these sidecars: (org.freedesktop.Telepathy.Salut.Plugin.Test)
>** (telepathy-salut:17620): DEBUG: initialize: 0xaba420 on connection manager 0xadd020
>(telepathy-salut:17620): tp-glib-DEBUG: started version 0.7.1 (telepathy-glib version 0.17.5)
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for nickname: "avahi/file-transfer/metadata.py"
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for first-name: "test"
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for last-name: "suite"
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for published-name: "testsuite"
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_class_init: called.
>(telepathy-salut:17620): salut-DEBUG: gabble_capabilities_init: 0xafa020
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_init: called.
>** (telepathy-salut:17620): DEBUG: create_channel_managers: 0xaba420 on connection 0xafa020
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_register: 0xafa020: bus name org.freedesktop.Telepathy.Connection.salut.local_xmpp.testsuite; object path /org/freedesktop/Telepathy/Connection/salut/local_xmpp/testsuite
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_start: wocky-meta-porter.c:1169: listening on port 5298
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_learn_caps: learning http://telepathy.freedesktop.org/caps#pmAwMK9hWdMMhgygNcUKoydJxpY=
>
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 4294967295, now 1, for reason 1
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 1, for reason 1
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams'>
>
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 1, now 0, for reason 0
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 0, for reason 0
>(telepathy-salut:17620): salut-DEBUG: sidecars_conn_status_changed_cb: connected; requesting sidecars from plugins
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_all_for_now_cb: Contact list received
>tp_group_mixin_change_flags: emitting group flags changed
>  added    : [PROPERTIES]
>  removed  : []
>  flags now: [PROPERTIES|MEMBERS_CHANGED_DETAILED]
>(telepathy-salut:17620): tp-glib/groups-DEBUG: tp_group_mixin_change_flags: No change: 6144 includes all the bits of 0 and none of 0
>tp_group_mixin_change_flags: emitting group flags changed
>  added    : [PROPERTIES]
>  removed  : []
>  flags now: [PROPERTIES|MEMBERS_CHANGED_DETAILED]
>(telepathy-salut:17620): tp-glib/groups-DEBUG: tp_group_mixin_change_flags: No change: 6144 includes all the bits of 0 and none of 0
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_set_list_received: Initial contacts: 
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_contact_created: Adding testsuite@testsuite to contacts
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_add_service: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 0): added
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='j
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_add_service: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 1): added
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: abber:client' xmlns:stream='http://etherx.jabber.org/streams'>
>
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17620): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'testsuite@testsuite' refcount 0 --> 1
>(telepathy-salut:17620): salut-DEBUG: contact_resolved_cb: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 0): contact testsuite@testsuite resolved
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_process_caps: Called for testsuite@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/caps' 'pmAwMK9hWdMMhgygNcUKoydJxpY='
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_change_caps: setting caps for testsuite@testsuite (thanks to an existing cache entry)
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: Contact testsuite@testsuite: subscribe=Y publish=Y ''
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [1 (testsuite@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [1 (testsuite@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([1 changed], [0 removed])
>(telepathy-salut:17620): salut-DEBUG: contact_change_cb: Emitting contact changes for testsuite@testsuite: 255
>(telepathy-salut:17620): salut-DEBUG: _contact_manager_contact_alias_changed: Emitting AliasesChanged
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17620): salut-DEBUG: contact_resolved_cb: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 1): contact testsuite@testsuite resolved
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_process_caps: Called for testsuite@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/caps' 'pmAwMK9hWdMMhgygNcUKoydJxpY='
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_change_caps: capabilities of testsuite@testsuite did not actually change
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_contact_created: Adding test-ft-metadata@testsuite to contacts
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_add_service: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): added
>(telepathy-salut:17620): salut-DEBUG: contact_resolved_cb: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): contact test-ft-metadata@testsuite resolved
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_process_caps: Called for test-ft-metadata@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/fake-client' 'XDbFaoNtLjsD1Rm5XCLnF586udM='
>(telepathy-salut:17620): salut-DEBUG: disco_waiter_new: created waiter 0xb2f880 for contact test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: salut_disco_request: Creating disco request 0xad2600 for test-ft-metadata@testsuite
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'test-ft-metadata@testsuite' refcount 0 --> 1
>(telepathy-salut:17620): wocky-DEBUG: process_one_address: wocky-ll-connection-factory.c:190: connecting to 127.0.0.1 (port 50256)
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: Contact test-ft-metadata@testsuite: subscribe=Y publish=Y ''
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [2 (test-ft-metadata@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 2
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [2 (test-ft-metadata@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([1 changed], [0 removed])
>(telepathy-salut:17620): salut-DEBUG: contact_change_cb: Emitting contact changes for test-ft-metadata@testsuite: 255
>(telepathy-salut:17620): salut-DEBUG: _contact_manager_contact_alias_changed: Emitting AliasesChanged
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17620): wocky-DEBUG: connect_to_host_cb: wocky-ll-connection-factory.c:151: made connection
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' to="test-ft-metadata@testsuite" from="testsuite@testsuite" version="1.0">
>
>(telepathy-salut:17620): wocky-DEBUG: send_open_cb: wocky-ll-connector.c:408: successfully sent stream open, now waiting for other side to too
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_new: New channel request at 0xb37ef0: ctype=org.freedesktop.Telepathy.Channel.Type.ContactList htype=3 handle=2 suppress=0
>(telepathy-salut:17620): tp-glib/connection-DEBUG: satisfy_request: completing queued request 0xb37ef0 with success, channel_type=org.freedesktop.Telepathy.Channel.Type.ContactList, handle_type=3, handle=2, suppress_handler=0
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_free: Freeing channel request at 0xb37ef0: ctype=org.freedesktop.Telepathy.Channel.Type.ContactList htype=3 handle=2 suppress=0
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='testsuite@testsuite' version='1.0' from='test-ft-metadata@testsuite'><stream:features xmlns:stream='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'/>
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: to = 'testsuite@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: version = '1.0' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: from = 'test-ft-metadata@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: Received stanza
>* features xmlns='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'
>(telepathy-salut:17620): wocky-DEBUG: recv_open_cb: wocky-ll-connector.c:361: connected, sending stream features but not expecting anything back
>(telepathy-salut:17620): wocky-DEBUG: _write_node_tree: Serializing tree:
>* features xmlns='http://etherx.jabber.org/streams'
>(telepathy-salut:17620): wocky-DEBUG: Writing xml: <stream:features/>
>(telepathy-salut:17620): wocky-DEBUG: made_connection_connect_cb: wocky-meta-porter.c:953: connected
>(telepathy-salut:17620): wocky-DEBUG: _write_node_tree: Serializing tree:
>* iq xmlns='jabber:client' type='get' to='test-ft-metadata@testsuite' from='testsuite@testsuite' id='131684919157'
>    * query xmlns='http://jabber.org/protocol/disco#info' node='http://telepathy.freedesktop.org/fake-client#XDbFaoNtLjsD1Rm5XCLnF586udM='
>(telepathy-salut:17620): wocky-DEBUG: Writing xml: <iq type="get" to="test-ft-metadata@testsuite" from="testsuite@testsuite" id="131684919157"><query node="http://telepathy.freedesktop.org/fake-client#XDbFaoNtLjsD1Rm5XCLnF586udM=" xmlns="http://jabber.org/protocol/disco#info"/></iq>
>(telepathy-salut:17620): wocky-DEBUG: wocky_ll_connector_dispose: wocky-ll-connector.c:152: dispose called
>(telepathy-salut:17620): wocky-DEBUG: handle_stanza: wocky-c2s-porter.c:1023: Stanza not handled
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <iq xmlns='jabber:client' from='test-ft-metadata@testsuite' type='result' id='131684919157' to='testsuite@testsuite'><query xmlns='http://jabber.org/protocol/disco#info'><feature var='jabber:iq:oob'/><feature var='http://telepathy.freedesktop.org/xmpp/file-transfer-metadata'/></query></iq></stream:stream>
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: Received stanza
>* iq xmlns='jabber:client' from='test-ft-metadata@testsuite' type='result' id='131684919157' to='testsuite@testsuite'
>    * query xmlns='http://jabber.org/protocol/disco#info'
>        * feature var='jabber:iq:oob'
>        * feature var='http://telepathy.freedesktop.org/xmpp/file-transfer-metadata'
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: wocky-xmpp-reader.c:602: Stream ended
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_change_caps: setting caps for test-ft-metadata@testsuite (thanks to test-ft-metadata@testsuite)
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_get_contact: Getting contact for: test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: disco_waiter_free: freeing waiter 0xb2f880 for contact test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: disco_waiter_list_free: list (nil)
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_unhold: wocky-meta-porter.c:426: Porter to 'test-ft-metadata@testsuite' refcount 1 --> 0
>(telepathy-salut:17620): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17620): wocky-DEBUG: stanza_received_cb: wocky-c2s-porter.c:1294: Error receiving stanza: Connection has been closed for reading stanzas
>(telepathy-salut:17620): wocky-DEBUG: porter_remote_error_cb: wocky-meta-porter.c:254: remote error in porter, close it
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'test-ft-metadata@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_force_close_async: wocky-c2s-porter.c:2053: remote is already closed, close the XMPP connection
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'test-ft-metadata@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: connection_force_close_cb: wocky-c2s-porter.c:1266: XMPP connection has been closed; complete the force close operation
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_finalize: wocky-c2s-porter.c:568: finalize porter 0xb2b990
>(telepathy-salut:17620): wocky-DEBUG: _new_connection: wocky-meta-porter.c:601: New connection from 127.0.0.1!
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='testsuite@testsuite' version='1.0' from='test-ft-metadata@testsuite'>
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: to = 'testsuite@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: version = '1.0' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: from = 'test-ft-metadata@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: recv_open_cb: wocky-ll-connector.c:371: stream opened from test-ft-metadata@testsuite, sending open back
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' to="test-ft-metadata@testsuite" from="" version="1.0">
>
>(telepathy-salut:17620): wocky-DEBUG: send_open_cb: wocky-ll-connector.c:418: connected, sending stream features but not expecting anything back
>(telepathy-salut:17620): wocky-DEBUG: _write_node_tree: Serializing tree:
>* features xmlns='http://etherx.jabber.org/streams'
>(telepathy-salut:17620): wocky-DEBUG: Writing xml: <stream:features/>
>(telepathy-salut:17620): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17620): wocky-DEBUG: wocky_ll_connector_dispose: wocky-ll-connector.c:152: dispose called
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <iq to='testsuite@testsuite' from='test-ft-metadata@testsuite' id='gibber-file-transfer-0' type='set'><query xmlns='jabber:iq:oob'><url mimeType='text/plain' type='file' size='16'>http://127.0.0.1:53882/gibber-file-transfer-0/The%20foo.txt</url><desc>A nice file to test</desc></query></iq>
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: Received stanza
>* iq xmlns='jabber:client' to='testsuite@testsuite' from='test-ft-metadata@testsuite' id='gibber-file-transfer-0' type='set'
>    * query xmlns='jabber:iq:oob'
>        * url mimeType='text/plain' type='file' size='16'
>            "http://127.0.0.1:53882/gibber-file-transfer-0/The%20foo.txt"
>        * desc
>            "A nice file to test"
>(telepathy-salut:17620): salut-DEBUG: message_stanza_callback: new incoming channel
>(telepathy-salut:17620): salut-DEBUG: salut_file_transfer_channel_new_from_stanza: Received file offer with id 'gibber-file-transfer-0'
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'test-ft-metadata@testsuite' refcount 0 --> 1
>(telepathy-salut:17620): salut-DEBUG: salut_file_transfer_channel_constructor: New FT channel created: /org/freedesktop/Telepathy/Connection/salut/local_xmpp/testsuite/FileTransferChannel/0xae6900 (contact: test-ft-metadata@testsuite, initiator: test-ft-metadata@testsuite, file: "The foo.txt", size: 16)
>(telepathy-salut:17620): salut-DEBUG: get_socket_channel: local socket /tmp/tp-ft-337908496
>(telepathy-salut:17620): salut-DEBUG: accept_local_socket_connection: Client connected to local socket
>** (telepathy-salut:17620): DEBUG: http_client_finished_chunks_cb: Finished HTTP chunked file transfer
>(telepathy-salut:17620): wocky-DEBUG: _write_node_tree: Serializing tree:
>* iq xmlns='jabber:client' type='result' from='testsuite@testsuite' to='test-ft-metadata@testsuite' id='gibber-file-transfer-0'
>(telepathy-salut:17620): wocky-DEBUG: Writing xml: <iq type="result" from="testsuite@testsuite" to="test-ft-metadata@testsuite" id="gibber-file-transfer-0"/>
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_unhold: wocky-meta-porter.c:426: Porter to 'test-ft-metadata@testsuite' refcount 1 --> 0
>(telepathy-salut:17620): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17620): salut-DEBUG: salut_file_transfer_channel_do_close: Emitting closed signal for /org/freedesktop/Telepathy/Connection/salut/local_xmpp/testsuite/FileTransferChannel/0xae6900
>(telepathy-salut:17620): salut-DEBUG: file_channel_closed: Removing channel with handle 2
>(telepathy-salut:17620): salut-DEBUG: browser_removed: Browser removed for test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_remove_service: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): remove requested
>(telepathy-salut:17620): salut-DEBUG: contact_drop_resolver: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): removed, 0 left for test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: salut_contact_lost: Contact test-ft-metadata@testsuite: disappeared from the local link
>(telepathy-salut:17620): salut-DEBUG: contact_change_cb: Emitting contact changes for test-ft-metadata@testsuite: 2
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : []
>  removed       : [2 (test-ft-metadata@testsuite)]
>  local_pending : []
>  remote_pending: []
>  actor         : 0
>  reason        : 0: unspecified reason
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : []
>  removed       : [2 (test-ft-metadata@testsuite)]
>  local_pending : []
>  remote_pending: []
>  actor         : 0
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([0 changed], [1 removed])
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 0, now 2, for reason 1
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 2, for reason 1
>(telepathy-salut:17620): salut-DEBUG: salut_im_factory_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_muc_manager_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_roomlist_manager_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_connection_shut_down: connection may still be open; closing it: 0xafa020
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'test-ft-metadata@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_close: wocky-xmpp-writer.c:325: Writing stream close: </stream:stream>
>
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'testsuite@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_close: wocky-xmpp-writer.c:325: Writing stream close: </stream:stream>
>
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: </stream
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: :stream>
>
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: wocky-xmpp-reader.c:602: Stream ended
>(telepathy-salut:17620): wocky-DEBUG: stanza_received_cb: wocky-c2s-porter.c:1290: Remote connection has been closed
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_finalize: wocky-c2s-porter.c:568: finalize porter 0xb2b8b0
>(telepathy-salut:17620): wocky-DEBUG: stanza_received_cb: wocky-c2s-porter.c:1294: Error receiving stanza: Connection got disconnected
>(telepathy-salut:17620): wocky-DEBUG: porter_close_cb: wocky-meta-porter.c:1410: Failed to close porter: Connection got disconnected
>(telepathy-salut:17620): salut-DEBUG: closed_cb: close failed: Failed to close at least one porter
>(telepathy-salut:17620): tp-glib/params-DEBUG: connection_shutdown_finished_cb: dereferenced connection
>(telepathy-salut:17620): salut-DEBUG: salut_disco_dispose: dispose called
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_dispose: dispose called
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_finalize: called with 0xb07d40
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_dispose: Disposing contact manager
>(telepathy-salut:17620): salut-DEBUG: salut_muc_manager_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_roomlist_manager_close_all: closing channels
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_finalize: 0xafa020
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_contacts_mixin_finalize: 0xafa020
>(telepathy-salut:17620): salut-DEBUG: gabble_capabilities_finalize: 0xafa020
>(telepathy-salut:17620): salut-DEBUG: salut_connection_finalize: Finalizing connection
>(telepathy-salut:17620): salut-DEBUG: salut_contact_dispose: Contact testsuite@testsuite: Disposing contact
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_finalize: wocky-c2s-porter.c:568: finalize porter 0xb2ba70
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for nickname: "avahi/file-transfer/metadata.py"
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for first-name: "test"
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for last-name: "suite"
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for published-name: "testsuite"
>(telepathy-salut:17620): salut-DEBUG: gabble_capabilities_init: 0xafa210
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_init: called.
>** (telepathy-salut:17620): DEBUG: create_channel_managers: 0xaba420 on connection 0xafa210
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_register: 0xafa210: bus name org.freedesktop.Telepathy.Connection.salut.local_xmpp.testsuite; object path /org/freedesktop/Telepathy/Connection/salut/local_xmpp/testsuite
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_start: wocky-meta-porter.c:1169: listening on port 5298
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_learn_caps: learning http://telepathy.freedesktop.org/caps#pmAwMK9hWdMMhgygNcUKoydJxpY=
>
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 4294967295, now 1, for reason 1
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 1, for reason 1
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams'>
>
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 1, now 0, for reason 0
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 0, for reason 0
>(telepathy-salut:17620): salut-DEBUG: sidecars_conn_status_changed_cb: connected; requesting sidecars from plugins
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='j
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: abber:client' xmlns:stream='http://etherx.jabber.org/streams'>
>
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17620): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'testsuite@testsuite' refcount 0 --> 1
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_all_for_now_cb: Contact list received
>tp_group_mixin_change_flags: emitting group flags changed
>  added    : [PROPERTIES]
>  removed  : []
>  flags now: [PROPERTIES|MEMBERS_CHANGED_DETAILED]
>(telepathy-salut:17620): tp-glib/groups-DEBUG: tp_group_mixin_change_flags: No change: 6144 includes all the bits of 0 and none of 0
>tp_group_mixin_change_flags: emitting group flags changed
>  added    : [PROPERTIES]
>  removed  : []
>  flags now: [PROPERTIES|MEMBERS_CHANGED_DETAILED]
>(telepathy-salut:17620): tp-glib/groups-DEBUG: tp_group_mixin_change_flags: No change: 6144 includes all the bits of 0 and none of 0
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_set_list_received: Initial contacts: 
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_contact_created: Adding testsuite@testsuite to contacts
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_add_service: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 0): added
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_add_service: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 1): added
>(telepathy-salut:17620): salut-DEBUG: contact_resolved_cb: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 0): contact testsuite@testsuite resolved
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_process_caps: Called for testsuite@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/caps' 'pmAwMK9hWdMMhgygNcUKoydJxpY='
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_change_caps: setting caps for testsuite@testsuite (thanks to an existing cache entry)
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: Contact testsuite@testsuite: subscribe=Y publish=Y ''
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [1 (testsuite@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [1 (testsuite@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([1 changed], [0 removed])
>(telepathy-salut:17620): salut-DEBUG: contact_change_cb: Emitting contact changes for testsuite@testsuite: 255
>(telepathy-salut:17620): salut-DEBUG: _contact_manager_contact_alias_changed: Emitting AliasesChanged
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17620): salut-DEBUG: contact_resolved_cb: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 1): contact testsuite@testsuite resolved
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_process_caps: Called for testsuite@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/caps' 'pmAwMK9hWdMMhgygNcUKoydJxpY='
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_change_caps: capabilities of testsuite@testsuite did not actually change
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_contact_created: Adding test-ft-metadata@testsuite to contacts
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_add_service: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): added
>(telepathy-salut:17620): salut-DEBUG: contact_resolved_cb: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): contact test-ft-metadata@testsuite resolved
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_process_caps: Called for test-ft-metadata@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/fake-client' 'XDbFaoNtLjsD1Rm5XCLnF586udM='
>(telepathy-salut:17620): salut-DEBUG: disco_waiter_new: created waiter 0xb3f940 for contact test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: salut_disco_request: Creating disco request 0xad2680 for test-ft-metadata@testsuite
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'test-ft-metadata@testsuite' refcount 0 --> 1
>(telepathy-salut:17620): wocky-DEBUG: process_one_address: wocky-ll-connection-factory.c:190: connecting to 127.0.0.1 (port 43754)
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: Contact test-ft-metadata@testsuite: subscribe=Y publish=Y ''
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [2 (test-ft-metadata@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 2
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [2 (test-ft-metadata@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([1 changed], [0 removed])
>(telepathy-salut:17620): salut-DEBUG: contact_change_cb: Emitting contact changes for test-ft-metadata@testsuite: 255
>(telepathy-salut:17620): salut-DEBUG: _contact_manager_contact_alias_changed: Emitting AliasesChanged
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_new: New channel request at 0xb37cd0: ctype=org.freedesktop.Telepathy.Channel.Type.ContactList htype=3 handle=2 suppress=0
>(telepathy-salut:17620): tp-glib/connection-DEBUG: satisfy_request: completing queued request 0xb37cd0 with success, channel_type=org.freedesktop.Telepathy.Channel.Type.ContactList, handle_type=3, handle=2, suppress_handler=0
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_free: Freeing channel request at 0xb37cd0: ctype=org.freedesktop.Telepathy.Channel.Type.ContactList htype=3 handle=2 suppress=0
>(telepathy-salut:17620): wocky-DEBUG: connect_to_host_cb: wocky-ll-connection-factory.c:151: made connection
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' to="test-ft-metadata@testsuite" from="testsuite@testsuite" version="1.0">
>
>(telepathy-salut:17620): wocky-DEBUG: send_open_cb: wocky-ll-connector.c:408: successfully sent stream open, now waiting for other side to too
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='testsuite@testsuite' version='1.0' from='test-ft-metadata@testsuite'><stream:features xmlns:stream='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'/>
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: to = 'testsuite@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: version = '1.0' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: from = 'test-ft-metadata@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: Received stanza
>* features xmlns='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'
>(telepathy-salut:17620): wocky-DEBUG: recv_open_cb: wocky-ll-connector.c:361: connected, sending stream features but not expecting anything back
>(telepathy-salut:17620): wocky-DEBUG: _write_node_tree: Serializing tree:
>* features xmlns='http://etherx.jabber.org/streams'
>(telepathy-salut:17620): wocky-DEBUG: Writing xml: <stream:features/>
>(telepathy-salut:17620): wocky-DEBUG: made_connection_connect_cb: wocky-meta-porter.c:953: connected
>(telepathy-salut:17620): wocky-DEBUG: _write_node_tree: Serializing tree:
>* iq xmlns='jabber:client' type='get' to='test-ft-metadata@testsuite' from='testsuite@testsuite' id='99013107471'
>    * query xmlns='http://jabber.org/protocol/disco#info' node='http://telepathy.freedesktop.org/fake-client#XDbFaoNtLjsD1Rm5XCLnF586udM='
>(telepathy-salut:17620): wocky-DEBUG: Writing xml: <iq type="get" to="test-ft-metadata@testsuite" from="testsuite@testsuite" id="99013107471"><query node="http://telepathy.freedesktop.org/fake-client#XDbFaoNtLjsD1Rm5XCLnF586udM=" xmlns="http://jabber.org/protocol/disco#info"/></iq>
>(telepathy-salut:17620): wocky-DEBUG: wocky_ll_connector_dispose: wocky-ll-connector.c:152: dispose called
>(telepathy-salut:17620): wocky-DEBUG: handle_stanza: wocky-c2s-porter.c:1023: Stanza not handled
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <iq xmlns='jabber:client' from='test-ft-metadata@testsuite' type='result' id='99013107471' to='testsuite@testsuite'><query xmlns='http://jabber.org/protocol/disco#info'><feature var='jabber:iq:oob'/><feature var='http://telepathy.freedesktop.org/xmpp/file-transfer-metadata'/></query></iq></stream:stream>
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: Received stanza
>* iq xmlns='jabber:client' from='test-ft-metadata@testsuite' type='result' id='99013107471' to='testsuite@testsuite'
>    * query xmlns='http://jabber.org/protocol/disco#info'
>        * feature var='jabber:iq:oob'
>        * feature var='http://telepathy.freedesktop.org/xmpp/file-transfer-metadata'
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: wocky-xmpp-reader.c:602: Stream ended
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_change_caps: setting caps for test-ft-metadata@testsuite (thanks to test-ft-metadata@testsuite)
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_get_contact: Getting contact for: test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: disco_waiter_free: freeing waiter 0xb3f940 for contact test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: disco_waiter_list_free: list (nil)
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_unhold: wocky-meta-porter.c:426: Porter to 'test-ft-metadata@testsuite' refcount 1 --> 0
>(telepathy-salut:17620): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17620): wocky-DEBUG: stanza_received_cb: wocky-c2s-porter.c:1294: Error receiving stanza: Connection has been closed for reading stanzas
>(telepathy-salut:17620): wocky-DEBUG: porter_remote_error_cb: wocky-meta-porter.c:254: remote error in porter, close it
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'test-ft-metadata@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_force_close_async: wocky-c2s-porter.c:2053: remote is already closed, close the XMPP connection
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'test-ft-metadata@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: connection_force_close_cb: wocky-c2s-porter.c:1266: XMPP connection has been closed; complete the force close operation
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_finalize: wocky-c2s-porter.c:568: finalize porter 0xb2bd10
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_new: New channel request at 0xb37810: ctype=org.freedesktop.Telepathy.Channel.Type.FileTransfer htype=1 handle=2 suppress=1
>(telepathy-salut:17620): salut-DEBUG: salut_ft_manager_handle_request: File transfer request
>(telepathy-salut:17620): tp-glib/connection-DEBUG: fail_channel_request: completing queued request 0xb37810 with error, channel_type=org.freedesktop.Telepathy.Channel.Type.FileTransfer, handle_type=1, handle=2, suppress_handler=1
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_free: Freeing channel request at 0xb37810: ctype=org.freedesktop.Telepathy.Channel.Type.FileTransfer htype=1 handle=2 suppress=1
>(telepathy-salut:17620): salut-DEBUG: browser_removed: Browser removed for test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_remove_service: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): remove requested
>(telepathy-salut:17620): salut-DEBUG: contact_drop_resolver: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): removed, 0 left for test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: salut_contact_lost: Contact test-ft-metadata@testsuite: disappeared from the local link
>(telepathy-salut:17620): salut-DEBUG: contact_change_cb: Emitting contact changes for test-ft-metadata@testsuite: 2
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : []
>  removed       : [2 (test-ft-metadata@testsuite)]
>  local_pending : []
>  remote_pending: []
>  actor         : 0
>  reason        : 0: unspecified reason
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : []
>  removed       : [2 (test-ft-metadata@testsuite)]
>  local_pending : []
>  remote_pending: []
>  actor         : 0
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([0 changed], [1 removed])
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 0, now 2, for reason 1
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 2, for reason 1
>(telepathy-salut:17620): salut-DEBUG: salut_contact_dispose: Contact testsuite@testsuite: Disposing contact
>(telepathy-salut:17620): salut-DEBUG: salut_im_factory_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_muc_manager_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_roomlist_manager_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_connection_shut_down: connection may still be open; closing it: 0xafa210
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'testsuite@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_close: wocky-xmpp-writer.c:325: Writing stream close: </stream:stream>
>
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: </stream
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: :stream>
>
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: wocky-xmpp-reader.c:602: Stream ended
>(telepathy-salut:17620): wocky-DEBUG: stanza_received_cb: wocky-c2s-porter.c:1290: Remote connection has been closed
>(telepathy-salut:17620): salut-DEBUG: closed_cb: connection properly closed
>(telepathy-salut:17620): tp-glib/params-DEBUG: connection_shutdown_finished_cb: dereferenced connection
>(telepathy-salut:17620): salut-DEBUG: salut_disco_dispose: dispose called
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_dispose: dispose called
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_finalize: called with 0xafea80
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_dispose: Disposing contact manager
>(telepathy-salut:17620): salut-DEBUG: salut_muc_manager_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_roomlist_manager_close_all: closing channels
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_finalize: 0xafa210
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_contacts_mixin_finalize: 0xafa210
>(telepathy-salut:17620): salut-DEBUG: gabble_capabilities_finalize: 0xafa210
>(telepathy-salut:17620): salut-DEBUG: salut_connection_finalize: Finalizing connection
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_finalize: wocky-c2s-porter.c:568: finalize porter 0xb2bc30
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for nickname: "avahi/file-transfer/metadata.py"
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for first-name: "test"
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for last-name: "suite"
>(telepathy-salut:17620): tp-glib/params-DEBUG: tp_base_protocol_sanitize_parameters: using specified value for published-name: "testsuite"
>(telepathy-salut:17620): salut-DEBUG: gabble_capabilities_init: 0xafa400
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_init: called.
>** (telepathy-salut:17620): DEBUG: create_channel_managers: 0xaba420 on connection 0xafa400
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_register: 0xafa400: bus name org.freedesktop.Telepathy.Connection.salut.local_xmpp.testsuite; object path /org/freedesktop/Telepathy/Connection/salut/local_xmpp/testsuite
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_start: wocky-meta-porter.c:1169: listening on port 5298
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_learn_caps: learning http://telepathy.freedesktop.org/caps#pmAwMK9hWdMMhgygNcUKoydJxpY=
>
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 4294967295, now 1, for reason 1
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 1, for reason 1
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams'>
>
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 1, now 0, for reason 0
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 0, for reason 0
>(telepathy-salut:17620): salut-DEBUG: sidecars_conn_status_changed_cb: connected; requesting sidecars from plugins
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_all_for_now_cb: Contact list received
>tp_group_mixin_change_flags: emitting group flags changed
>  added    : [PROPERTIES]
>  removed  : []
>  flags now: [PROPERTIES|MEMBERS_CHANGED_DETAILED]
>(telepathy-salut:17620): tp-glib/groups-DEBUG: tp_group_mixin_change_flags: No change: 6144 includes all the bits of 0 and none of 0
>tp_group_mixin_change_flags: emitting group flags changed
>  added    : [PROPERTIES]
>  removed  : []
>  flags now: [PROPERTIES|MEMBERS_CHANGED_DETAILED]
>(telepathy-salut:17620): tp-glib/groups-DEBUG: tp_group_mixin_change_flags: No change: 6144 includes all the bits of 0 and none of 0
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_set_list_received: Initial contacts: 
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_contact_created: Adding testsuite@testsuite to contacts
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_add_service: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 0): added
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='j
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_add_service: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 1): added
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: abber:client' xmlns:stream='http://etherx.jabber.org/streams'>
>
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17620): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'testsuite@testsuite' refcount 0 --> 1
>(telepathy-salut:17620): salut-DEBUG: contact_resolved_cb: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 0): contact testsuite@testsuite resolved
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_process_caps: Called for testsuite@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/caps' 'pmAwMK9hWdMMhgygNcUKoydJxpY='
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_change_caps: setting caps for testsuite@testsuite (thanks to an existing cache entry)
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: Contact testsuite@testsuite: subscribe=Y publish=Y ''
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [1 (testsuite@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [1 (testsuite@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([1 changed], [0 removed])
>(telepathy-salut:17620): salut-DEBUG: contact_change_cb: Emitting contact changes for testsuite@testsuite: 255
>(telepathy-salut:17620): salut-DEBUG: _contact_manager_contact_alias_changed: Emitting AliasesChanged
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17620): salut-DEBUG: contact_resolved_cb: Contact testsuite@testsuite: Resolver (testsuite@testsuite _presence._tcp intf: 0 proto: 1): contact testsuite@testsuite resolved
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_process_caps: Called for testsuite@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/caps' 'pmAwMK9hWdMMhgygNcUKoydJxpY='
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_change_caps: capabilities of testsuite@testsuite did not actually change
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_contact_created: Adding test-ft-metadata@testsuite to contacts
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_add_service: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): added
>(telepathy-salut:17620): salut-DEBUG: contact_resolved_cb: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): contact test-ft-metadata@testsuite resolved
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_process_caps: Called for test-ft-metadata@testsuite with 'sha-1' 'http://telepathy.freedesktop.org/fake-client' 'BUPzDeEGHiaStVVQabtzocdns18='
>(telepathy-salut:17620): salut-DEBUG: disco_waiter_new: created waiter 0xb72980 for contact test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: salut_disco_request: Creating disco request 0xb30f40 for test-ft-metadata@testsuite
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_hold: wocky-meta-porter.c:388: Porter to 'test-ft-metadata@testsuite' refcount 0 --> 1
>(telepathy-salut:17620): wocky-DEBUG: process_one_address: wocky-ll-connection-factory.c:190: connecting to 127.0.0.1 (port 43438)
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: Contact test-ft-metadata@testsuite: subscribe=Y publish=Y ''
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [2 (test-ft-metadata@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 2
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : [2 (test-ft-metadata@testsuite)]
>  removed       : []
>  local_pending : []
>  remote_pending: []
>  actor         : 1
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([1 changed], [0 removed])
>(telepathy-salut:17620): salut-DEBUG: contact_change_cb: Emitting contact changes for test-ft-metadata@testsuite: 255
>(telepathy-salut:17620): salut-DEBUG: _contact_manager_contact_alias_changed: Emitting AliasesChanged
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>(telepathy-salut:17620): wocky-DEBUG: connect_to_host_cb: wocky-ll-connection-factory.c:151: made connection
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_open: wocky-xmpp-writer.c:298: Writing stream opening: <?xml version='1.0' encoding='UTF-8'?>
><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' to="test-ft-metadata@testsuite" from="testsuite@testsuite" version="1.0">
>
>(telepathy-salut:17620): wocky-DEBUG: send_open_cb: wocky-ll-connector.c:408: successfully sent stream open, now waiting for other side to too
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_new: New channel request at 0x2abbfc001830: ctype=org.freedesktop.Telepathy.Channel.Type.ContactList htype=3 handle=2 suppress=0
>(telepathy-salut:17620): tp-glib/connection-DEBUG: satisfy_request: completing queued request 0x2abbfc001830 with success, channel_type=org.freedesktop.Telepathy.Channel.Type.ContactList, handle_type=3, handle=2, suppress_handler=0
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_free: Freeing channel request at 0x2abbfc001830: ctype=org.freedesktop.Telepathy.Channel.Type.ContactList htype=3 handle=2 suppress=0
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='testsuite@testsuite' version='1.0' from='test-ft-metadata@testsuite'><stream:features xmlns:stream='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'/>
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:431: Received stream opening: stream, prefix: stream, uri: http://etherx.jabber.org/streams
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: to = 'testsuite@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: version = '1.0' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: handle_stream_open: wocky-xmpp-reader.c:450: Stream opening attribute: from = 'test-ft-metadata@testsuite' (prefix: <no prefix>, uri: <no uri>)
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: Received stanza
>* features xmlns='http://etherx.jabber.org/streams' to='testsuite@testsuite' from='test-ft-metadata@testsuite'
>(telepathy-salut:17620): wocky-DEBUG: recv_open_cb: wocky-ll-connector.c:361: connected, sending stream features but not expecting anything back
>(telepathy-salut:17620): wocky-DEBUG: _write_node_tree: Serializing tree:
>* features xmlns='http://etherx.jabber.org/streams'
>(telepathy-salut:17620): wocky-DEBUG: Writing xml: <stream:features/>
>(telepathy-salut:17620): wocky-DEBUG: made_connection_connect_cb: wocky-meta-porter.c:953: connected
>(telepathy-salut:17620): wocky-DEBUG: _write_node_tree: Serializing tree:
>* iq xmlns='jabber:client' type='get' to='test-ft-metadata@testsuite' from='testsuite@testsuite' id='229984230258'
>    * query xmlns='http://jabber.org/protocol/disco#info' node='http://telepathy.freedesktop.org/fake-client#BUPzDeEGHiaStVVQabtzocdns18='
>(telepathy-salut:17620): wocky-DEBUG: Writing xml: <iq type="get" to="test-ft-metadata@testsuite" from="testsuite@testsuite" id="229984230258"><query node="http://telepathy.freedesktop.org/fake-client#BUPzDeEGHiaStVVQabtzocdns18=" xmlns="http://jabber.org/protocol/disco#info"/></iq>
>(telepathy-salut:17620): wocky-DEBUG: wocky_ll_connector_dispose: wocky-ll-connector.c:152: dispose called
>(telepathy-salut:17620): wocky-DEBUG: handle_stanza: wocky-c2s-porter.c:1023: Stanza not handled
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: <iq xmlns='jabber:client' from='test-ft-metadata@testsuite' type='result' id='229984230258' to='testsuite@testsuite'><query xmlns='http://jabber.org/protocol/disco#info'><feature var='jabber:iq:oob'/></query></iq></stream:stream>
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: Received stanza
>* iq xmlns='jabber:client' from='test-ft-metadata@testsuite' type='result' id='229984230258' to='testsuite@testsuite'
>    * query xmlns='http://jabber.org/protocol/disco#info'
>        * feature var='jabber:iq:oob'
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: wocky-xmpp-reader.c:602: Stream ended
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_change_caps: setting caps for test-ft-metadata@testsuite (thanks to test-ft-metadata@testsuite)
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_get_contact: Getting contact for: test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: disco_waiter_free: freeing waiter 0xb72980 for contact test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: disco_waiter_list_free: list (nil)
>(telepathy-salut:17620): wocky-DEBUG: wocky_meta_porter_unhold: wocky-meta-porter.c:426: Porter to 'test-ft-metadata@testsuite' refcount 1 --> 0
>(telepathy-salut:17620): wocky-DEBUG: maybe_start_timeout: wocky-meta-porter.c:278: Started porter timeout...
>(telepathy-salut:17620): wocky-DEBUG: stanza_received_cb: wocky-c2s-porter.c:1294: Error receiving stanza: Connection has been closed for reading stanzas
>(telepathy-salut:17620): wocky-DEBUG: porter_remote_error_cb: wocky-meta-porter.c:254: remote error in porter, close it
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'test-ft-metadata@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_force_close_async: wocky-c2s-porter.c:2053: remote is already closed, close the XMPP connection
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'test-ft-metadata@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: connection_force_close_cb: wocky-c2s-porter.c:1266: XMPP connection has been closed; complete the force close operation
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_finalize: wocky-c2s-porter.c:568: finalize porter 0xb2bc30
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_new: New channel request at 0xb2c0a0: ctype=org.freedesktop.Telepathy.Channel.Type.FileTransfer htype=1 handle=2 suppress=1
>(telepathy-salut:17620): salut-DEBUG: salut_ft_manager_handle_request: File transfer request
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_get_contact: Getting contact for: test-ft-metadata@testsuite
>(telepathy-salut:17620): tp-glib/connection-DEBUG: fail_channel_request: completing queued request 0xb2c0a0 with error, channel_type=org.freedesktop.Telepathy.Channel.Type.FileTransfer, handle_type=1, handle=2, suppress_handler=1
>(telepathy-salut:17620): tp-glib/connection-DEBUG: channel_request_free: Freeing channel request at 0xb2c0a0: ctype=org.freedesktop.Telepathy.Channel.Type.FileTransfer htype=1 handle=2 suppress=1
>(telepathy-salut:17620): salut-DEBUG: browser_removed: Browser removed for test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: salut_avahi_contact_remove_service: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): remove requested
>(telepathy-salut:17620): salut-DEBUG: contact_drop_resolver: Contact test-ft-metadata@testsuite: Resolver (test-ft-metadata@testsuite _presence._tcp intf: 0 proto: 0): removed, 0 left for test-ft-metadata@testsuite
>(telepathy-salut:17620): salut-DEBUG: salut_contact_lost: Contact test-ft-metadata@testsuite: disappeared from the local link
>(telepathy-salut:17620): salut-DEBUG: contact_change_cb: Emitting contact changes for test-ft-metadata@testsuite: 2
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_one_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_emit_presence_update: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_presence_hash: called.
>(telepathy-salut:17620): tp-glib/presence-DEBUG: construct_simple_presence_hash: called.
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : []
>  removed       : [2 (test-ft-metadata@testsuite)]
>  local_pending : []
>  remote_pending: []
>  actor         : 0
>  reason        : 0: unspecified reason
>emit_members_changed_signals: emitting members changed
>  message       : ""
>  added         : []
>  removed       : [2 (test-ft-metadata@testsuite)]
>  local_pending : []
>  remote_pending: []
>  actor         : 0
>  reason        : 0: unspecified reason
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/groups-DEBUG: change_members: not emitting signal, nothing changed
>(telepathy-salut:17620): tp-glib/contact-lists-DEBUG: tp_base_contact_list_contacts_changed_internal: ContactsChanged([0 changed], [1 removed])
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 0, now 2, for reason 1
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_base_connection_change_status: emitting status-changed to 2, for reason 1
>(telepathy-salut:17620): salut-DEBUG: salut_im_factory_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_muc_manager_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_roomlist_manager_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_connection_shut_down: connection may still be open; closing it: 0xafa400
>(telepathy-salut:17620): wocky-DEBUG: porter_closing_cb: wocky-meta-porter.c:226: porter to 'testsuite@testsuite' closing, remove it from our records
>(telepathy-salut:17620): wocky-DEBUG: wocky_xmpp_writer_stream_close: wocky-xmpp-writer.c:325: Writing stream close: </stream:stream>
>
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: </stream
>(telepathy-salut:17620): wocky-DEBUG: Parsing chunk: :stream>
>
>(telepathy-salut:17620): wocky-DEBUG: _end_element_ns: wocky-xmpp-reader.c:602: Stream ended
>(telepathy-salut:17620): wocky-DEBUG: stanza_received_cb: wocky-c2s-porter.c:1290: Remote connection has been closed
>(telepathy-salut:17620): salut-DEBUG: closed_cb: connection properly closed
>(telepathy-salut:17620): tp-glib/params-DEBUG: connection_shutdown_finished_cb: dereferenced connection
>(telepathy-salut:17620): salut-DEBUG: salut_disco_dispose: dispose called
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_dispose: dispose called
>(telepathy-salut:17620): salut-DEBUG: salut_presence_cache_finalize: called with 0xaf0e80
>(telepathy-salut:17620): salut-DEBUG: salut_contact_manager_dispose: Disposing contact manager
>(telepathy-salut:17620): salut-DEBUG: salut_muc_manager_close_all: closing channels
>(telepathy-salut:17620): salut-DEBUG: salut_roomlist_manager_close_all: closing channels
>(telepathy-salut:17620): tp-glib/presence-DEBUG: tp_presence_mixin_finalize: 0xafa400
>(telepathy-salut:17620): tp-glib/connection-DEBUG: tp_contacts_mixin_finalize: 0xafa400
>(telepathy-salut:17620): salut-DEBUG: gabble_capabilities_finalize: 0xafa400
>(telepathy-salut:17620): salut-DEBUG: salut_connection_finalize: Finalizing connection
>(telepathy-salut:17620): salut-DEBUG: salut_contact_dispose: Contact testsuite@testsuite: Disposing contact
>(telepathy-salut:17620): wocky-DEBUG: wocky_c2s_porter_finalize: wocky-c2s-porter.c:568: finalize porter 0xb2bdf0
>tp-glib-Message: Got disconnected from the session bus
>tp-glib-Message: Exiting
>(telepathy-salut:17620): tp-glib/proxy-DEBUG: tp_proxy_dispose: 0xada120
>(telepathy-salut:17620): tp-glib/proxy-DEBUG: tp_proxy_invalidate: 0xada120: Proxy unreferenced
>(telepathy-salut:17620): tp-glib/proxy-DEBUG: tp_proxy_finalize: 0xada120

Actions: View

Attachments on bug 46391: 57387

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.