Re: [squid-users] Failed download files larger that 2GB through proxy with ICAP.

Following your suggestion I've captured traffic betwen ICAP and Squid.
So I have following situation:
1) tcpdump from ICAP<->SQUID session.
.....
11:11:05.853539 IP 127.0.0.1.49824 > 127.0.0.1.1345: . ack 2156829681
win 28786 <nop,nop,timestamp 1727787379 1727787376>
11:11:05.857550 IP 127.0.0.1.49824 > 127.0.0.1.1345: P
2157715132:2157717185(2053) ack 2156829681 win 28786 <nop,nop,timestamp
1727787383 1727787376>
11:11:05.857598 IP 127.0.0.1.1345 > 127.0.0.1.49824: P
2156829681:2156830511(830) ack 2157717185 win 30720 <nop,nop,timestamp
1727787383 1727787383>
11:11:05.861173 IP 127.0.0.1.49824 > 127.0.0.1.1345: P
2157717185:2157719238(2053) ack 2156830511 win 28786 <nop,nop,timestamp
1727787387 1727787383>
11:11:05.864532 IP 127.0.0.1.49824 > 127.0.0.1.1345: P
2157719238:2157723337(4099) ack 2156830511 win 28786 <nop,nop,timestamp
1727787390 1727787383>
11:11:05.877022 IP 127.0.0.1.1345 > 127.0.0.1.49824: R
2156830511:2156830511(0) ack 2157723337 win 30720 <nop,nop,timestamp
1727787403 1727787387>

As we can see, the last packet was with TCP RST flag set (127.0.0.1.1345
> 127.0.0.1.49824: R).

tcpdump -nn -XXX -r icap_session 'tcp[tcpflags] & (tcp-rst) !=0'
reading from file icap_session, link-type EN10MB (Ethernet)
11:11:05.877022 IP 127.0.0.1.1345 > 127.0.0.1.49824: R
4247311891:4247311891(0) ack 4241360957 win 30720 <nop,nop,timestamp
1727787403 1727787387>
        0x0000: 0000 0000 0000 0000 0000 0000 0800 4500 ..............E.
        0x0010: 0034 0901 4000 4006 33c1 7f00 0001 7f00 .4..@.@.3.......
        0x0020: 0001 0541 c2a0 fd28 d613 fcce 083d 8014 ...A...(.....=..
        0x0030: 7800 af8d 0000 0101 080a 66fb f18b 66fb x.........f...f.
        0x0040: f17b .{

2) trace log from squid

...
2009/08/20 11:11:05.878| exiting
BodyPipe::tellMoreBodySpaceAvailable(0x9bd42f0)
2009/08/20 11:11:05.878| comm_iocallbackpending: 0
2009/08/20 11:11:05.878| comm_calliocallback: 0
2009/08/20 11:11:05.878| comm_calliocallback: 0
2009/08/20 11:11:05.878| commio_call_callback: called for 15
2009/08/20 11:11:05.878| ICAP/ICAPXaction.cc(59) 0x9baa878 read returned
0
2009/08/20 11:11:05.878| ICAPModXact::noteCommRead called [FD
15wr;Rrw(5)p(2)S(2)/P icapx6]
2009/08/20 11:11:05.879| ICAP/ICAPXaction.cc:334: exception: commStatus
== COMM_OK
2009/08/20 11:11:05.879| ICAPModXact::noteCommRead caught an exception:
commStatus == COMM_OK [FD 15w;Rrw(5)p(2)S(2)/P icapx6]
2009/08/20 11:11:05.879| ICAPModXact will stop, reason: exception
2009/08/20 11:11:05.879| ICAPModXact::noteCommRead ends job [FD
15w;Rrw(5)p(2)S(2)/P icapx6]
2009/08/20 11:11:05.879| ICAP/ICAPModXact.cc(1062) swan sings [FD
15w;Rrw(5)p(2)S(2)/P icapx6]
2009/08/20 11:11:05.879| ICAP/ICAPModXact.cc(423) will NOT wait for the
last write [FD 15w;Rrw(5)p(2)S(2)/P icapx6]
2009/08/20 11:11:05.879| ICAP/ICAPModXact.cc(434) will no longer write
[FD 15w;Rrw(5)p(2)S(2)/P icapx6]
2009/08/20 11:11:05.879| ICAP/ICAPModXact.cc(567) will stop consuming
[FD 15w;Rrp(2)S(2)/wP icapx6]
2009/08/20 11:11:05.879| BodyPipe.cc(20) 0x9baa8d4 will not consume from
0x9bd42f0*3
...

Exception caught in ICAP/ICAPXaction.cc:334 occured at 11:11:05.879. And
the reason is TCP packet with RST flag set.

3) ICAP server logs following
The child 13559 not exited normaly.signaled with signal:25

Signal 25 is SIGXFSZ and man 7 signal shows us that:
SIGXFSZ 25,25,31 Core File size limit exceeded (4.2BSD)

So theoretically ICAP process/subprocess have to create core file
(because of default action specified in standart).
But I can't find it unfortunatelly.

-----Original Message-----
From: Henrik Nordstrom <henrik_at_henriknordstrom.net>
To: juris.krumins_at_ctco.lv
Cc: Amos Jeffries <squid3_at_treenet.co.nz>, squid-users_at_squid-cache.org
Subject: Re: [squid-users] Failed download files larger that 2GB through
proxy with ICAP.
Date: Wed, 19 Aug 2009 21:20:19 +0200

ons 2009-08-19 klockan 16:34 +0300 skrev Juris Krumins:
> Here is trace log from squid-3.1.0.13. The behavior is the same.
> Adaptation::Icap::Xaction::noteCommRead throwing exception, looks like
> because of loosing connection with ICAP server (as far as I can
> understand this situation).

wireshark is a great tool for seeing what happens at the ICAP level
without having to dive into debug logs. There you can very easily see if
what Amos suspects is correct.

Regards
Henrik
Received on Thu Aug 20 2009 - 08:59:46 MDT