USB connection reset by peer issue

#66

During development Nikias encountered a serious issue due to him being able to only use USB 1.1 on his computer.

All N*128 sized usb packets sent cause the device to issue a "reset by peer" and afcd to shutdown the connection causing I/O errors afterwards (since afcd shutdown).

I did not encounter it using USB 2.0, however I also sometimes had sudden I/O errors. Now it became evident that I am also experiencing the same issue but for me it must be N*512.

After hundred million hours of debugging we have simple testcase to hopefully verify if just us or everyone is affected:

#include <stdio.h>
#include <string.h>

#define MUX_HEADER_SIZE 28
#define AFC_HEADER_SIZE 48

int main(int argc, char **argv)
{
    char buf[512];

    memset(buf, 0xAA, sizeof(buf));

    FILE *f = fopen("testfile128", "w");
    if (f) {
    printf("producing 128 bytes packet ...\n");
        fwrite(buf, 1, 128-MUX_HEADER_SIZE-AFC_HEADER_SIZE, f);
    fclose(f);
    }
    f = fopen("testfile256", "w");
    if (f) {
    printf("producing 256 bytes packet ...\n");
        fwrite(buf, 1, 256-MUX_HEADER_SIZE-AFC_HEADER_SIZE, f);
    fclose(f);
    }
    f = fopen("testfile384", "w");
    if (f) {
    printf("producing 384 bytes packet ...\n");
        fwrite(buf, 1, 384-MUX_HEADER_SIZE-AFC_HEADER_SIZE, f);
    fclose(f);
    }
    f = fopen("testfile512", "w");
    if (f) {
    printf("producing 512 bytes packet ...\n");
        fwrite(buf, 1, 512-MUX_HEADER_SIZE-AFC_HEADER_SIZE, f);
    fclose(f);
    }
}

Compile/install, mount your device and in the mount directory run "afctest". Then watch the connection breaking down when writing some packet. To get a better glimpse at the actual sent data one can use usbmon.

If it worked for you, also make sure that usbmon showed your raw usb packet being the right size, anything not N*128/N*512 will not trigger the issue.

Perhaps someone sees a pattern or can hint at where to look to fix it?

More debug info (512 byte overall usb packet):

libiphone debug:

...
afc_lock: Locked
afc_file_write: Write length: 484
afc_dispatch_packet: Offset: 8
afc_dispatch_packet: sent the first now go with the second
afc_dispatch_packet: Length: 484
afc_dispatch_packet: Buffer:
0000: 0a 00 00 00 00 04 00 00 00 00 00 00 00 00 00 00   | ................
0010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0060: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0070: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0080: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0090: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
00a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
00b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
00c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
00d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
00e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
00f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0100: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0110: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0120: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0130: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0140: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0150: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0160: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0170: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0180: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
0190: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
01a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
01b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
01c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
01d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   | ................
01e0: 00 00 00 00                                       | ....







afc_receive_data: Just didn't get enough.
afc_unlock: Unlocked
afc_file_write: uh oh?
...

usbmon output:

...
f1020a80 411.668917 S Bo:3:024:4 - 512 = 00000006 00000200 7568cc45 00109cf0 00182a84 50100200 00000200 
0a000000 00040000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000
f1020a80 411.669002 C Bo:3:024:4 0 512 >
f2006300 414.664129 C Bi:3:024:5 -2 0
f2006300 414.664176 S Bi:3:024:5 - 16384 <
f1101600 416.670462 S Bo:3:024:4 - 132 = 00000006 00000084 7568cc45 00109ed4 00182a84 50100200 00000084
43464136 4c504141 68000000 00000000 68000000 00000000 f73b0000 00000000
0a000000 00000000 2f695475 6e65735f 436f6e74 726f6c2f 6954756e 65732f69
54756e65 73204c69 62726172 792e6974 6c702f4c 69627261 72792e69 7464622d
6a6f7572 6e616c00
f1101600 416.670755 C Bo:3:024:4 0 132 >
...

USB error message received from the device:

...
received error message: handleMuxTCPInput th.th_seq = 1089340, expected 1088752
...

Reported by Martin S. · August 1st, 2009 @ 11:22 AM

Activity

Nikias Bassen
Hi

as I assume that we both are not alone with this issue I implemented a workaround inside usbmuxd, available in my git repo. The workaround splits the problematic packets into two packets and thus avoiding this problem. However it is a HACK and hacks are not the right way, but until a fix is found (kernel?, libusb?) we have at least a working usbmuxd.

If you still want to test if you are affected, and that would be good to know, you need to configure usbmuxd with --disable-hacks to diable the workaround.

August 2nd, 2009 @ 05:46 AM
Martin S.
- State changed from new to open
Superb Nikias. This fixes the issue for now, still I guess this is something in the low level usb communication. Anyone with a latest kernel could verify this?

August 2nd, 2009 @ 05:40 PM
Martin S.
- State changed from open to resolved
Ok, finally a solution has been found which appears to not be a hack. The issue is documented for usb bulk transfers whereas the usb data is only sent if the data length is smaller than wMaxPacketSize or 0. So if your usb packet was exactly wMacPacketSize (which surprisingly was 64 bytes for usb 1.1 and 512 for usb 2.0), it was not sent!

Nikias now added code to usbmuxd to fix this and it appears to work and looks like the proper solution compared to the "split packet up" hack.

August 3rd, 2009 @ 07:14 PM

Please Sign in or create a free account to add a new ticket.

With your very own profile, you can contribute to projects, track your activity, watch tickets, receive and update tickets through your email and much more.