[Pidgin] #6091: Can only receive files but not send to some users over AIM, pidgin incorrectly says other user canceled

Pidgin trac at pidgin.im
Sat Jun 14 18:36:32 EDT 2008


#6091: Can only receive files but not send to some users over AIM, pidgin
incorrectly says other user canceled
-------------------+--------------------------------------------------------
Reporter:  dave1g  |       Owner:  MarkDoliner      
    Type:  defect  |      Status:  new              
Priority:  minor   |   Component:  AIM              
 Version:  2.4.2   |    Keywords:  aim file transfer
 Pending:  0       |  
-------------------+--------------------------------------------------------
 I successfully received a file transfer from a user, when I tried to send
 one back,  pidgin claims the other user "canceled" the transfer, which was
 not the case.
 AIM direct connect also works fine.

 she is using "aol instant messenger aim version 6.5.12.1"

 I see this
 {{{
 (6:13:30 PM) Offering to send 100_2834.JPG to soothsayergirl
 (6:13:36 PM) soothsayergirl canceled the transfer of 100_2834.JPG
 }}}

 she saw this

 {{{
 ATTENTION (06:13:22 p.m.): File Transfer session .
 ATTENTION (06:13:22 p.m.): File Transfer session .
 ATTENTION (06:13:29 p.m.): File Transfer session initiated.
 An Unknown Failure Occurred.
 }}}

 and here is the debug log for that failed attempt from me to her ( I have
 removed all of the oscar rate change logs so it is readable)

 {{{
 (18:13:30) win32placement: Window RECT: L:226 R:721 T:100 B:428
 (18:13:30) win32placement: Working Area RECT: L:0 R:1680 T:0 B:960
 (18:13:30) oscar: Calculating checksum of C:\Documents and
 Settings\David\Desktop\100_2834.JPG
 (18:13:30) oscar: Checksum of C:\Documents and
 Settings\David\Desktop\100_2834.JPG calculated
 (18:13:30) network: Listening on port: 10001
 (18:13:30) util: requested to fetch
 (http://192.168.5.1:80/Public_UPNP_C3), full=0, user_agent=((null)),
 http11=1
 (18:13:30) dnsquery: Performing DNS lookup for 192.168.5.1
 (18:13:30) dnsquery: IP resolved for 192.168.5.1
 (18:13:30) proxy: Attempting connection to 192.168.5.1
 (18:13:30) proxy: Connecting to 192.168.5.1:80 with no proxy
 (18:13:30) proxy: Connection in progress
 (18:13:30) proxy: Connected to 192.168.5.1:80.
 (18:13:30) util: Request: 'POST /Public_UPNP_C3 HTTP/1.1
 HOST: 192.168.5.1:80
 SOAPACTION: "urn:schemas-upnp-
 org:service:WANIPConnection:1#AddPortMapping"
 CONTENT-TYPE: text/xml ; charset="utf-8"
 CONTENT-LENGTH: 649

 <?xml version="1.0" encoding="utf-8"?>
 <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"
 s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
 <s:Body>
 <u:AddPortMapping xmlns:u="urn:schemas-upnp-
 org:service:WANIPConnection:1">
 <NewRemoteHost></NewRemoteHost>
 <NewExternalPort>10001</NewExternalPort>
 <NewProtocol>TCP</NewProtocol>
 <NewInternalPort>10001</NewInternalPort>
 <NewInternalClient>192.168.5.10</NewInternalClient>
 <NewEnabled>1</NewEnabled>
 <NewPortMappingDescription>PURPLE_UPNP_PORT_FORWARD</NewPortMappingDescription>
 <NewLeaseDuration>0</NewLeaseDuration>
 </u:AddPortMapping>
 </s:Body>
 </s:Envelope>'
 (18:13:30) util: Response headers: 'HTTP/1.1 200 OK
 CONTENT-LENGTH:267
 CONTENT-TYPE:text/xml; charset="utf-8"
 EXT:
 SERVER:Ambit OS/1.0 UPnP/1.0 AMBIT-UPNP/1.0

 '
 (18:13:30) upnp: Successfully completed port mapping operation
 (18:13:30) stun: using server stunserver.org
 (18:13:30) oscar: Sent message to soothsayergirl.
 (18:13:36) oscar: Incoming rendezvous message of type 32, user
 soothsayergirl, status 0
 (18:13:36) oscar: Remote user wants to try a different connection method
 (18:13:36) dnsquery: Performing DNS lookup for 64.12.201.144
 (18:13:36) dnsquery: IP resolved for 64.12.201.144
 (18:13:36) proxy: Attempting connection to 64.12.201.144
 (18:13:36) proxy: Connecting to 64.12.201.144:5190 with no proxy
 (18:13:36) proxy: Connection in progress
 (18:13:36) proxy: Connected to 64.12.201.144:5190.
 (18:13:36) oscar: Outgoing peer proxy frame with type=0x0004,
 unknown=0x00000000, flags=0x0000, and payload length=37
 (18:13:36) oscar: Incoming peer proxy frame with type=0x0005,
 unknown=0x00000000, flags=0x0220, and payload length=0
 (18:13:45) oscar: incomingim_ch1: unknown TLV 0x000d (len 27)
 (18:13:45) oscar: incomingim_ch1: unknown TLV 0x0013 (len 1)
 (18:13:45) oscar: Received IM from soothsayergirl with 1 parts
 (18:13:45) oscar: Parsing IM part, charset=0x0000, charsubset=0x0000,
 datalen=579
 (18:13:45) sound: Playing C:\Program
 Files\Pidgin\sounds\purple\receive.wav
 (18:13:51) gtkimhtml: empty queue, more closing tags than open tags!
 (18:13:51) gtkimhtml: empty queue, more closing tags than open tags!
 (18:13:51) gtkimhtml: empty queue, more closing tags than open tags!
 (18:13:56) oscar: Sending IM, charset=0x0000, charsubset=0x0000, length=18
 (18:13:56) sound: Playing C:\Program Files\Pidgin\sounds\purple\send.wav
 (18:13:56) oscar: Sent message to soothsayergirl.
 (18:13:57) gtkimhtml: empty queue, more closing tags than open tags!
 (18:13:57) gtkimhtml: empty queue, more closing tags than open tags!
 (18:13:57) gtkimhtml: empty queue, more closing tags than open tags!
 (18:13:57) oscar: Sending IM, charset=0x0000, charsubset=0x0000,
 length=511
 (18:13:57) oscar: Sent message to soothsayergirl.
 (18:14:04) oscar: incomingim_ch1: unknown TLV 0x000d (len 27)
 (18:14:04) oscar: incomingim_ch1: unknown TLV 0x0013 (len 1)
 (18:14:04) oscar: Received IM from soothsayergirl with 1 parts
 }}}

 and here is a successful attempt from her to me
 {{{
 (6:21:13 PM) David Grohmann: can you send me a file
 (6:22:05 PM) soothsayergirl is offering to send file water.jpg
 (6:22:09 PM) Starting transfer of water.jpg from soothsayergirl
 (6:22:21 PM) Transfer of file water.jpg complete
 }}}
 debug:
 {{{
 (18:21:13) oscar: Sent message to soothsayergirl.
 (18:22:05) oscar: Incoming rendezvous message of type 32, user
 soothsayergirl, status 0
 (18:22:09) dnsquery: Performing DNS lookup for 68.196.149.16
 (18:22:09) dnsquery: Performing DNS lookup for 192.168.1.102
 (18:22:09) dnsquery: IP resolved for 68.196.149.16
 (18:22:09) proxy: Attempting connection to 68.196.149.16
 (18:22:09) proxy: Connecting to 68.196.149.16:61560 with no proxy
 (18:22:09) proxy: Connection in progress
 (18:22:09) dnsquery: IP resolved for 192.168.1.102
 (18:22:09) proxy: Attempting connection to 192.168.1.102
 (18:22:09) proxy: Connecting to 192.168.1.102:61560 with no proxy
 (18:22:09) proxy: Connection in progress
 (18:22:14) oscar: Peer connection timed out after 5 seconds.  Trying next
 method...
 (18:22:14) network: Listening on port: 10001
 (18:22:14) util: requested to fetch
 (http://192.168.5.1:80/Public_UPNP_C3), full=0, user_agent=((null)),
 http11=1
 (18:22:14) dnsquery: Performing DNS lookup for 192.168.5.1
 (18:22:14) dnsquery: IP resolved for 192.168.5.1
 (18:22:14) proxy: Attempting connection to 192.168.5.1
 (18:22:14) proxy: Connecting to 192.168.5.1:80 with no proxy
 (18:22:14) proxy: Connection in progress
 (18:22:14) proxy: Connected to 192.168.5.1:80.
 (18:22:14) util: Request: 'POST /Public_UPNP_C3 HTTP/1.1
 HOST: 192.168.5.1:80
 SOAPACTION: "urn:schemas-upnp-
 org:service:WANIPConnection:1#AddPortMapping"
 CONTENT-TYPE: text/xml ; charset="utf-8"
 CONTENT-LENGTH: 649

 <?xml version="1.0" encoding="utf-8"?>
 <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"
 s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
 <s:Body>
 <u:AddPortMapping xmlns:u="urn:schemas-upnp-
 org:service:WANIPConnection:1">
 <NewRemoteHost></NewRemoteHost>
 <NewExternalPort>10001</NewExternalPort>
 <NewProtocol>TCP</NewProtocol>
 <NewInternalPort>10001</NewInternalPort>
 <NewInternalClient>192.168.5.10</NewInternalClient>
 <NewEnabled>1</NewEnabled>
 <NewPortMappingDescription>PURPLE_UPNP_PORT_FORWARD</NewPortMappingDescription>
 <NewLeaseDuration>0</NewLeaseDuration>
 </u:AddPortMapping>
 </s:Body>
 </s:Envelope>'
 (18:22:14) util: Response headers: 'HTTP/1.1 200 OK
 CONTENT-LENGTH:267
 CONTENT-TYPE:text/xml; charset="utf-8"
 EXT:
 SERVER:Ambit OS/1.0 UPnP/1.0 AMBIT-UPNP/1.0

 '
 (18:22:14) upnp: Successfully completed port mapping operation
 (18:22:14) stun: using server stunserver.org
 (18:22:14) oscar: Sent message to soothsayergirl.
 (18:22:16) oscar: Scheduling destruction of FLAP connection of type 0x000d
 (18:22:16) oscar: Destroying oscar connection of type 0x000d.  Disconnect
 reason is 4
 (18:22:16) oscar: Disconnected.  Code is 0x0000 and msg is Remote host
 closed connection.
 (18:22:20) oscar: Incoming rendezvous message of type 32, user
 soothsayergirl, status 0
 (18:22:20) oscar: Remote user wants to try a different connection method
 (18:22:20) dnsquery: Performing DNS lookup for ars.oscar.aol.com
 (18:22:20) dnsquery: IP resolved for ars.oscar.aol.com
 (18:22:20) proxy: Attempting connection to 64.12.201.185
 (18:22:20) proxy: Connecting to ars.oscar.aol.com:5190 with no proxy
 (18:22:20) proxy: Connection in progress
 (18:22:20) proxy: Connected to ars.oscar.aol.com:5190.
 (18:22:20) oscar: Outgoing peer proxy frame with type=0x0002,
 unknown=0x00000000, flags=0x0000, and payload length=35
 (18:22:20) oscar: Incoming peer proxy frame with type=0x0003,
 unknown=0x00000000, flags=0x0220, and payload length=6
 (18:22:21) oscar: Sent message to soothsayergirl.
 (18:22:21) oscar: Incoming rendezvous message of type 32, user
 soothsayergirl, status 2
 (18:22:21) oscar: Incoming peer proxy frame with type=0x0005,
 unknown=0x00000000, flags=0x0220, and payload length=0
 (18:22:21) oscar: Incoming OFT frame from soothsayergirl with type=0x0101
 (18:22:36) oscar: Sending IM, charset=0x0000, charsubset=0x0000, length=6
 (18:22:36) sound: Playing C:\Program Files\Pidgin\sounds\purple\send.wav
 }}}

-- 
Ticket URL: <http://developer.pidgin.im/ticket/6091>
Pidgin <http://pidgin.im>
Pidgin


More information about the Tracker mailing list