[Pharo-project] Problem downloading packages with Monticello from Smalltalkhub because of setAcceptEncodingGzip
Hi, Lately I started to get ConnectionClosed errors when loading packages from Smalltalkhub by using Monticello. It's very likely to just be a problem with my environment, as I'm connecting through a university server, but I got stuck debugging it. Just to see if I can download packages normally I tried two things: ZnClient new systemPolicy; url: ' http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... '; beOneShot; get. ZnClient new systemPolicy; url: ' http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... '; setAcceptEncodingGzip; beOneShot; get. In the first case it works perfectly. However when I add 'setAcceptEncodingGzip' every time I get: [ConnectionClosed signal: 'Connection closed while waiting for data.'] in Socket>>waitForDataFor: but if I proceed from this error I get the right content. Monticello uses "setAcceptEncodingGzip" so I get the above error. If I remove it, it works ok. I've tried this with the Pharo2.0-one-click image on Mac OS (all the compression tests pass). Doing a request using curl with "Accept-Encoding: gzip,deflate" to the same url works ok. Am I missing something obvious? Cheers, Andrei
Hi Andrei, On 20 Mar 2013, at 17:01, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
Hi,
Lately I started to get ConnectionClosed errors when loading packages from Smalltalkhub by using Monticello. It's very likely to just be a problem with my environment, as I'm connecting through a university server, but I got stuck debugging it.
Just to see if I can download packages normally I tried two things: ZnClient new systemPolicy; url: 'http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-...'; beOneShot; get.
ZnClient new systemPolicy; url: 'http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-...'; setAcceptEncodingGzip; beOneShot; get.
In the first case it works perfectly. However when I add 'setAcceptEncodingGzip' every time I get: [ConnectionClosed signal: 'Connection closed while waiting for data.'] in Socket>>waitForDataFor: but if I proceed from this error I get the right content. Monticello uses "setAcceptEncodingGzip" so I get the above error. If I remove it, it works ok.
I've tried this with the Pharo2.0-one-click image on Mac OS (all the compression tests pass). Doing a request using curl with "Accept-Encoding: gzip,deflate" to the same url works ok.
Am I missing something obvious?
Cheers, Andrei
The problem that you mention (problems accessing monticello with gzip compression through some proxies) is a known issue: https://pharo.fogbugz.com/f/cases/6923 https://code.google.com/p/pharo/issues/detail?id=6986 The problem is, that to debug this, one (or I) has (have) to be behind your proxy. The other solution is that you help us. Add #logToTranscript to your Smalltalk code above and open the Transcript to see the HTTP wire protocol. Compare that with curl -v Somewhere there has to be some difference that matters... Regards, Sven -- Sven Van Caekenberghe http://stfx.eu Smalltalk is the Red Pill
On 2013-03-20, at 17:16, Sven Van Caekenberghe <sven@stfx.eu> wrote:
Hi Andrei,
On 20 Mar 2013, at 17:01, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
Hi,
Lately I started to get ConnectionClosed errors when loading packages from Smalltalkhub by using Monticello. It's very likely to just be a problem with my environment, as I'm connecting through a university server, but I got stuck debugging it.
Just to see if I can download packages normally I tried two things: ZnClient new systemPolicy; url: 'http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-...'; beOneShot; get.
ZnClient new systemPolicy; url: 'http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-...'; setAcceptEncodingGzip; beOneShot; get.
In the first case it works perfectly. However when I add 'setAcceptEncodingGzip' every time I get: [ConnectionClosed signal: 'Connection closed while waiting for data.'] in Socket>>waitForDataFor: but if I proceed from this error I get the right content. Monticello uses "setAcceptEncodingGzip" so I get the above error. If I remove it, it works ok.
I've tried this with the Pharo2.0-one-click image on Mac OS (all the compression tests pass). Doing a request using curl with "Accept-Encoding: gzip,deflate" to the same url works ok.
Am I missing something obvious?
Cheers, Andrei
The problem that you mention (problems accessing monticello with gzip compression through some proxies) is a known issue:
https://pharo.fogbugz.com/f/cases/6923 https://code.google.com/p/pharo/issues/detail?id=6986
The problem is, that to debug this, one (or I) has (have) to be behind your proxy. The other solution is that you help us.
Add #logToTranscript to your Smalltalk code above and open the Transcript to see the HTTP wire protocol. Compare that with curl -v
Somewhere there has to be some difference that matters...
I tried to get there while I was in argentina :) but I didn't manage :/
On 20 Mar 2013, at 17:19, Camillo Bruni <camillobruni@gmail.com> wrote:
On 2013-03-20, at 17:16, Sven Van Caekenberghe <sven@stfx.eu> wrote:
Hi Andrei,
On 20 Mar 2013, at 17:01, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
Hi,
Lately I started to get ConnectionClosed errors when loading packages from Smalltalkhub by using Monticello. It's very likely to just be a problem with my environment, as I'm connecting through a university server, but I got stuck debugging it.
Just to see if I can download packages normally I tried two things: ZnClient new systemPolicy; url: 'http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-...'; beOneShot; get.
ZnClient new systemPolicy; url: 'http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-...'; setAcceptEncodingGzip; beOneShot; get.
In the first case it works perfectly. However when I add 'setAcceptEncodingGzip' every time I get: [ConnectionClosed signal: 'Connection closed while waiting for data.'] in Socket>>waitForDataFor: but if I proceed from this error I get the right content. Monticello uses "setAcceptEncodingGzip" so I get the above error. If I remove it, it works ok.
I've tried this with the Pharo2.0-one-click image on Mac OS (all the compression tests pass). Doing a request using curl with "Accept-Encoding: gzip,deflate" to the same url works ok.
Am I missing something obvious?
Cheers, Andrei
The problem that you mention (problems accessing monticello with gzip compression through some proxies) is a known issue:
https://pharo.fogbugz.com/f/cases/6923 https://code.google.com/p/pharo/issues/detail?id=6986
The problem is, that to debug this, one (or I) has (have) to be behind your proxy. The other solution is that you help us.
Add #logToTranscript to your Smalltalk code above and open the Transcript to see the HTTP wire protocol. Compare that with curl -v
Somewhere there has to be some difference that matters...
I tried to get there while I was in argentina :) but I didn't manage :/
Well, go back then ! I never gave you permission to come as long as that bug was not fixed. Sven
Hi Sven, Bellow is the output of I got from #logToTranscript and by running curl with -v with http1.1 and with http1.0. Just from the zinc output I could figure out if the get request is http1.1 or http1.0 Let me know if you need any other data. ------------------------------------------------------------ ------------------------------------------------------------ ------------------------------------------------------------ ------------------------------ Output from Smalltalk: 2013-03-20 17:24:54 660707 I Wrote a ZnRequest(GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz) 2013-03-20 17:24:54 660707 D Sent headers User-Agent: Zinc HTTP Components 1.0 Accept-Encoding: gzip Connection: close Host: www.smalltalkhub.com Accept: */* 2013-03-20 17:24:54 660707 D ConnectionClosed: Connection closed while waiting for data. retrying 2013-03-20 17:24:55 660707 I Wrote a ZnRequest(GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz) 2013-03-20 17:24:55 660707 D Sent headers User-Agent: Zinc HTTP Components 1.0 Accept-Encoding: gzip Connection: close Host: www.smalltalkhub.com Accept: */* 2013-03-20 17:24:55 660707 D ConnectionClosed: Connection closed while waiting for data. retrying 2013-03-20 17:24:56 660707 I Wrote a ZnRequest(GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz) 2013-03-20 17:24:56 660707 D Sent headers User-Agent: Zinc HTTP Components 1.0 Accept-Encoding: gzip Connection: close Host: www.smalltalkhub.com Accept: */* 2013-03-20 17:24:58 660707 I Read a ZnResponse(200 OK application/x-monticello 3451B) 2013-03-20 17:24:58 660707 D Received headers Content-Encoding: gzip Content-Length: 3451 Server: KomHttpServer/7.1.3 (unix) Connection: close Content-Type: application/x-monticello X-Cache: HIT from proxy.unibe.ch Date: Wed, 20 Mar 2013 16:24:54 GMT Via: 1.0 bifor.unibe.ch (squid) Age: 3 Vary: Accept-Encoding 2013-03-20 17:24:58 660707 T GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz 200 3451B 4090ms ------------------------------------------------------------ ------------------------------------------------------------ ------------------------------------------------------------ ------------------------------ curl with http1.1 command: curl http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... -H "Accept-Encoding: gzip" --write-out "size_download=%{size_download}\n" --output /dev/null -v output: * About to connect() to www.smalltalkhub.com port 80 (#0) * Trying 88.190.31.116... % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* connected * Connected to www.smalltalkhub.com (88.190.31.116) port 80 (#0)
GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz HTTP/1.1 User-Agent: curl/7.24.0 (x86_64-apple-darwin12.0) libcurl/7.24.0 OpenSSL/0.9.8r zlib/1.2.5 Host: www.smalltalkhub.com Accept: */* Accept-Encoding: gzip
* HTTP 1.0, assume close after body < HTTP/1.0 200 OK < Date: Wed, 20 Mar 2013 16:41:16 GMT < Server: KomHttpServer/7.1.3 (unix) < Content-Type: application/x-monticello < Vary: Accept-Encoding < Content-Encoding: gzip < X-Cache: MISS from proxy.unibe.ch < Via: 1.0 bifor.unibe.ch (squid) < Connection: close < { [data not shown] 100 3307 0 3307 0 0 17741 0 --:--:-- --:--:-- --:--:-- 17972 * Closing connection #0 size_download=3307 ------------------------------------------------------------ ------------------------------------------------------------ ------------------------------------------------------------ ------------------------------ curl with http1.0 command: curl http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... --http1.0 -H "Accept-Encoding: gzip" --write-out "size_download=%{size_download}\n" --output /dev/null -v output: * About to connect() to www.smalltalkhub.com port 80 (#0) * Trying 88.190.31.116... % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* connected * Connected to www.smalltalkhub.com (88.190.31.116) port 80 (#0)
GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz HTTP/1.0 User-Agent: curl/7.24.0 (x86_64-apple-darwin12.0) libcurl/7.24.0 OpenSSL/0.9.8r zlib/1.2.5 Host: www.smalltalkhub.com Accept: */* Accept-Encoding: gzip
* HTTP 1.0, assume close after body < HTTP/1.0 200 OK < Date: Wed, 20 Mar 2013 16:41:16 GMT < Server: KomHttpServer/7.1.3 (unix) < Content-Type: application/x-monticello < Vary: Accept-Encoding < Content-Encoding: gzip < Age: 34 < X-Cache: HIT from proxy.unibe.ch < Via: 1.0 bifor.unibe.ch (squid) < Connection: close < { [data not shown] 100 3307 0 3307 0 0 1040k 0 --:--:-- --:--:-- --:--:-- 3229k * Closing connection #0 size_download=3307
Hi Andrei, I can see that you are using a transparent proxy based on Squid. Indeed, the response is HTTP 1.0 which logically implies a connection close. One difference that I see is related to the content-length in the response. There is none, which is OK when there is a connection close, but it shows in the Smalltalk trace, which is weird. And for the same file, /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz, Smalltalk reports a length of 3451B (probably after your proceeded from the exception), while curl reports size_download=3307, when I try from here, I also get 3451 bytes, Although unibe.ch is closer than Argentina, I am not on your network. You could try to put a breakpoint in ZnEntityReader>>#readEntity and see a bit what happens. We have to find out why readFrom: readStream usingType: contentType andLength: nil does not happen. Sven On 20 Mar 2013, at 17:48, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
Hi Sven,
Bellow is the output of I got from #logToTranscript and by running curl with -v with http1.1 and with http1.0. Just from the zinc output I could figure out if the get request is http1.1 or http1.0
Let me know if you need any other data.
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ Output from Smalltalk:
2013-03-20 17:24:54 660707 I Wrote a ZnRequest(GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz) 2013-03-20 17:24:54 660707 D Sent headers User-Agent: Zinc HTTP Components 1.0 Accept-Encoding: gzip Connection: close Host: www.smalltalkhub.com Accept: */*
2013-03-20 17:24:54 660707 D ConnectionClosed: Connection closed while waiting for data. retrying 2013-03-20 17:24:55 660707 I Wrote a ZnRequest(GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz) 2013-03-20 17:24:55 660707 D Sent headers User-Agent: Zinc HTTP Components 1.0 Accept-Encoding: gzip Connection: close Host: www.smalltalkhub.com Accept: */*
2013-03-20 17:24:55 660707 D ConnectionClosed: Connection closed while waiting for data. retrying 2013-03-20 17:24:56 660707 I Wrote a ZnRequest(GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz) 2013-03-20 17:24:56 660707 D Sent headers User-Agent: Zinc HTTP Components 1.0 Accept-Encoding: gzip Connection: close Host: www.smalltalkhub.com Accept: */*
2013-03-20 17:24:58 660707 I Read a ZnResponse(200 OK application/x-monticello 3451B) 2013-03-20 17:24:58 660707 D Received headers Content-Encoding: gzip Content-Length: 3451 Server: KomHttpServer/7.1.3 (unix) Connection: close Content-Type: application/x-monticello X-Cache: HIT from proxy.unibe.ch Date: Wed, 20 Mar 2013 16:24:54 GMT Via: 1.0 bifor.unibe.ch (squid) Age: 3 Vary: Accept-Encoding
2013-03-20 17:24:58 660707 T GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz 200 3451B 4090ms
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ curl with http1.1 command: curl http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... -H "Accept-Encoding: gzip" --write-out "size_download=%{size_download}\n" --output /dev/null -v output:
* About to connect() to www.smalltalkhub.com port 80 (#0) * Trying 88.190.31.116... % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* connected * Connected to www.smalltalkhub.com (88.190.31.116) port 80 (#0)
GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz HTTP/1.1 User-Agent: curl/7.24.0 (x86_64-apple-darwin12.0) libcurl/7.24.0 OpenSSL/0.9.8r zlib/1.2.5 Host: www.smalltalkhub.com Accept: */* Accept-Encoding: gzip
* HTTP 1.0, assume close after body < HTTP/1.0 200 OK < Date: Wed, 20 Mar 2013 16:41:16 GMT < Server: KomHttpServer/7.1.3 (unix) < Content-Type: application/x-monticello < Vary: Accept-Encoding < Content-Encoding: gzip < X-Cache: MISS from proxy.unibe.ch < Via: 1.0 bifor.unibe.ch (squid) < Connection: close < { [data not shown] 100 3307 0 3307 0 0 17741 0 --:--:-- --:--:-- --:--:-- 17972 * Closing connection #0 size_download=3307
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ curl with http1.0 command: curl http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... --http1.0 -H "Accept-Encoding: gzip" --write-out "size_download=%{size_download}\n" --output /dev/null -v output:
* About to connect() to www.smalltalkhub.com port 80 (#0) * Trying 88.190.31.116... % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* connected * Connected to www.smalltalkhub.com (88.190.31.116) port 80 (#0)
GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz HTTP/1.0 User-Agent: curl/7.24.0 (x86_64-apple-darwin12.0) libcurl/7.24.0 OpenSSL/0.9.8r zlib/1.2.5 Host: www.smalltalkhub.com Accept: */* Accept-Encoding: gzip
* HTTP 1.0, assume close after body < HTTP/1.0 200 OK < Date: Wed, 20 Mar 2013 16:41:16 GMT < Server: KomHttpServer/7.1.3 (unix) < Content-Type: application/x-monticello < Vary: Accept-Encoding < Content-Encoding: gzip < Age: 34 < X-Cache: HIT from proxy.unibe.ch < Via: 1.0 bifor.unibe.ch (squid) < Connection: close < { [data not shown] 100 3307 0 3307 0 0 1040k 0 --:--:-- --:--:-- --:--:-- 3229k * Closing connection #0 size_download=3307
Andrei, On 20 Mar 2013, at 19:05, Sven Van Caekenberghe <sven@stfx.eu> wrote:
One difference that I see is related to the content-length in the response. There is none, which is OK when there is a connection close, but it shows in the Smalltalk trace, which is weird.
And for the same file, /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz, Smalltalk reports a length of 3451B (probably after your proceeded from the exception), while curl reports size_download=3307, when I try from here, I also get 3451 bytes,
To make absolutely sure the curl call actually works, could you please try this: $ curl http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... -H "Accept-Encoding: gzip" | gunzip > foo.mcz % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 3307 0 3307 0 0 13558 0 --:--:-- --:--:-- --:--:-- 16131 $ file foo.mcz foo.mcz: Zip archive data, at least v2.0 to extract $ ls -l foo.mcz -rw-r--r-- 1 sven staff 3451 Mar 20 19:38 foo.mcz $ unzip -l foo.mcz Archive: foo.mcz Length Date Time Name -------- ---- ---- ---- 18 03-27-11 02:22 package 188 03-27-11 02:22 version 8588 03-27-11 02:22 snapshot/source.st 9014 03-27-11 02:22 snapshot.bin -------- ------- 17808 4 files Thanks, Sven -- Sven Van Caekenberghe http://stfx.eu Smalltalk is the Red Pill
Hi Sven, I'll will al these tomorrow when I get back to the office. Cheers, Andrei On Wed, Mar 20, 2013 at 7:40 PM, Sven Van Caekenberghe <sven@stfx.eu> wrote:
Andrei,
On 20 Mar 2013, at 19:05, Sven Van Caekenberghe <sven@stfx.eu> wrote:
One difference that I see is related to the content-length in the response. There is none, which is OK when there is a connection close, but it shows in the Smalltalk trace, which is weird.
And for the same file, /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz, Smalltalk reports a length of 3451B (probably after your proceeded from the exception), while curl reports size_download=3307, when I try from here, I also get 3451 bytes,
To make absolutely sure the curl call actually works, could you please try this:
$ curl http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... -H "Accept-Encoding: gzip" | gunzip > foo.mcz % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 3307 0 3307 0 0 13558 0 --:--:-- --:--:-- --:--:-- 16131
$ file foo.mcz foo.mcz: Zip archive data, at least v2.0 to extract
$ ls -l foo.mcz -rw-r--r-- 1 sven staff 3451 Mar 20 19:38 foo.mcz
$ unzip -l foo.mcz Archive: foo.mcz Length Date Time Name -------- ---- ---- ---- 18 03-27-11 02:22 package 188 03-27-11 02:22 version 8588 03-27-11 02:22 snapshot/source.st 9014 03-27-11 02:22 snapshot.bin -------- ------- 17808 4 files
Thanks,
Sven
-- Sven Van Caekenberghe http://stfx.eu Smalltalk is the Red Pill
Hi Sven, I tried all the command from your previous mail and the results are the same (output bellow). The strange thing is that I can download other files from smalltalkhub without problems. A short summary: ZnEntityReader>>#readEntity calls ZnEntityReader>>#readEntityFromStream which does 'GZipReadStream on: stream', after which 'readFrom:usingType:andLength:' is called. In a wrong call, 'GZipReadStream on: stream' always throws ConnectionClosed. This is handled in ZnClient>>executeWithRetriesRemaining: which keeps retrying until retryCount is 0. On the other hand for some files 'GZipReadStream on: stream' returns correctly, no exception is raised and it works ok. The exception is thrown in Socket>>waitForDataFor:ifClosed:ifTimedOut: because Socket>>primSocketConnectionStatus: returns 3 instead of 2. [(Time millisecondsSince: startTime) < msecsDelta] whileTrue: [ "here 'self primSocketConnectionStatus: socketHandle' is 2" (self primSocketReceiveDataAvailable: socketHandle) ifTrue: [Transcript crShow: ' hasData'. ^self]. "here 'self primSocketConnectionStatus: socketHandle' is 3, if there is no more content to be read so 'self isConnected' will be false." self isConnected ifFalse: [Transcript crShow: ' notConnected'.^closedBlock value]. self readSemaphore waitTimeoutMSecs: (msecsDelta - (Time millisecondsSince: startTime) max: 0). ]. That fact that this exception is raised during the call to 'GZipReadStream on: stream' seem to be the problem, as this does not allow readFrom: stream usingType: self contentType andLength: I hope this makes sense. I can try to dig more into it tomorrow. If you want me to look at other things let me know. Cheers, Andrei ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ $ curl http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... -H "Accept-Encoding: gzip" | gunzip > foo.mcz % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 3307 0 3307 0 0 7583 0 --:--:-- --:--:-- --:--:-- 8889 $ file foo.mcz foo.mcz: Zip archive data, at least v2.0 to extract $ ls -l foo.mcz -rw-r--r-- 1 andrei staff 3451 Mar 21 09:55 foo.mcz $ unzip -l foo.mcz Archive: foo.mcz Length Date Time Name -------- ---- ---- ---- 18 03-27-11 02:22 package 188 03-27-11 02:22 version 8588 03-27-11 02:22 snapshot/source.st 9014 03-27-11 02:22 snapshot.bin -------- ------- 17808 4 files
Andrei, On 21 Mar 2013, at 13:28, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
Hi Sven,
I tried all the command from your previous mail and the results are the same (output bellow).
Thanks for the feedback.
The strange thing is that I can download other files from smalltalkhub without problems.
What do you mean, that it only fails for that particular mcz file from StHub in Pharo, but that others are OK ? That would be very disturbing. Can you give an example of a call that does work, with the Transcript output, like ZnClient new logToTranscript; setAcceptEncodingGzip; get: 'http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-...'; response. 2013-03-20 23:17:17 995343 I Wrote a ZnRequest(GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz) 2013-03-20 23:17:17 995343 D Sent headers User-Agent: Zinc HTTP Components 1.0 Accept-Encoding: gzip Host: www.smalltalkhub.com Accept: */* 2013-03-20 23:17:17 995343 I Read a ZnResponse(200 OK application/x-monticello 3451B) 2013-03-20 23:17:17 995343 D Received headers Date: Wed, 20 Mar 2013 22:17:18 GMT Content-Encoding: gzip Transfer-Encoding: chunked Content-Length: 3451 Vary: Accept-Encoding Server: KomHttpServer/7.1.3 (unix) Content-Type: application/x-monticello 2013-03-20 23:17:17 995343 T GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz 200 3451B 272ms
A short summary:
ZnEntityReader>>#readEntity calls ZnEntityReader>>#readEntityFromStream which does 'GZipReadStream on: stream', after which 'readFrom:usingType:andLength:' is called. In a wrong call, 'GZipReadStream on: stream' always throws ConnectionClosed. This is handled in ZnClient>>executeWithRetriesRemaining: which keeps retrying until retryCount is 0. On the other hand for some files 'GZipReadStream on: stream' returns correctly, no exception is raised and it works ok.
The exception is thrown in Socket>>waitForDataFor:ifClosed:ifTimedOut: because Socket>>primSocketConnectionStatus: returns 3 instead of 2. [(Time millisecondsSince: startTime) < msecsDelta] whileTrue: [ "here 'self primSocketConnectionStatus: socketHandle' is 2" (self primSocketReceiveDataAvailable: socketHandle) ifTrue: [Transcript crShow: ' hasData'. ^self]. "here 'self primSocketConnectionStatus: socketHandle' is 3, if there is no more content to be read so 'self isConnected' will be false." self isConnected ifFalse: [Transcript crShow: ' notConnected'.^closedBlock value]. self readSemaphore waitTimeoutMSecs: (msecsDelta - (Time millisecondsSince: startTime) max: 0). ].
That fact that this exception is raised during the call to 'GZipReadStream on: stream' seem to be the problem, as this does not allow readFrom: stream usingType: self contentType andLength:
I hope this makes sense.
We probably do not have to look in the socket[stream] layer, the first place to look is in ZnEntityReader, more specifically: what was the situation wrt headers before it starts reading the body, what decisions were taken, and how far was/is it in the reading process.
I can try to dig more into it tomorrow. If you want me to look at other things let me know.
I am wondering whether we could set some temporary screen sharing over the internet, so that I can remotely work in an image running on a machine in your network⦠Sven
Cheers, Andrei
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
$ curl http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... -H "Accept-Encoding: gzip" | gunzip > foo.mcz % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 3307 0 3307 0 0 7583 0 --:--:-- --:--:-- --:--:-- 8889
$ file foo.mcz foo.mcz: Zip archive data, at least v2.0 to extract
$ ls -l foo.mcz -rw-r--r-- 1 andrei staff 3451 Mar 21 09:55 foo.mcz
$ unzip -l foo.mcz Archive: foo.mcz Length Date Time Name -------- ---- ---- ---- 18 03-27-11 02:22 package 188 03-27-11 02:22 version 8588 03-27-11 02:22 snapshot/source.st 9014 03-27-11 02:22 snapshot.bin -------- ------- 17808 4 files
Once I have a problem loading something from SS3 which was a piece of source code with non-utf8 characters (WideString). Could it be possible you have some non-utf characters in the source of the package you are loading? Cheers, On Thu, Mar 21, 2013 at 10:08 AM, Sven Van Caekenberghe <sven@stfx.eu>wrote:
Andrei,
On 21 Mar 2013, at 13:28, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
Hi Sven,
I tried all the command from your previous mail and the results are the same (output bellow).
Thanks for the feedback.
The strange thing is that I can download other files from smalltalkhub without problems.
What do you mean, that it only fails for that particular mcz file from StHub in Pharo, but that others are OK ? That would be very disturbing. Can you give an example of a call that does work, with the Transcript output, like
ZnClient new logToTranscript; setAcceptEncodingGzip; get: ' http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... '; response.
2013-03-20 23:17:17 995343 I Wrote a ZnRequest(GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz) 2013-03-20 23:17:17 995343 D Sent headers User-Agent: Zinc HTTP Components 1.0 Accept-Encoding: gzip Host: www.smalltalkhub.com Accept: */*
2013-03-20 23:17:17 995343 I Read a ZnResponse(200 OK application/x-monticello 3451B) 2013-03-20 23:17:17 995343 D Received headers Date: Wed, 20 Mar 2013 22:17:18 GMT Content-Encoding: gzip Transfer-Encoding: chunked Content-Length: 3451 Vary: Accept-Encoding Server: KomHttpServer/7.1.3 (unix) Content-Type: application/x-monticello
2013-03-20 23:17:17 995343 T GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz 200 3451B 272ms
A short summary:
ZnEntityReader>>#readEntity calls ZnEntityReader>>#readEntityFromStream which does 'GZipReadStream on: stream', after which 'readFrom:usingType:andLength:' is called. In a wrong call, 'GZipReadStream on: stream' always throws ConnectionClosed. This is handled in ZnClient>>executeWithRetriesRemaining: which keeps retrying until retryCount is 0. On the other hand for some files 'GZipReadStream on: stream' returns correctly, no exception is raised and it works ok.
The exception is thrown in Socket>>waitForDataFor:ifClosed:ifTimedOut: because Socket>>primSocketConnectionStatus: returns 3 instead of 2. [(Time millisecondsSince: startTime) < msecsDelta] whileTrue: [ "here 'self primSocketConnectionStatus: socketHandle' is 2" (self primSocketReceiveDataAvailable: socketHandle) ifTrue: [Transcript crShow: ' hasData'. ^self]. "here 'self primSocketConnectionStatus: socketHandle' is 3, if there is no more content to be read so 'self isConnected' will be false." self isConnected ifFalse: [Transcript crShow: ' notConnected'.^closedBlock value]. self readSemaphore waitTimeoutMSecs: (msecsDelta - (Time millisecondsSince: startTime) max: 0). ].
That fact that this exception is raised during the call to 'GZipReadStream on: stream' seem to be the problem, as this does not allow readFrom: stream usingType: self contentType andLength:
I hope this makes sense.
We probably do not have to look in the socket[stream] layer, the first place to look is in ZnEntityReader, more specifically: what was the situation wrt headers before it starts reading the body, what decisions were taken, and how far was/is it in the reading process.
I can try to dig more into it tomorrow. If you want me to look at other things let me know.
I am wondering whether we could set some temporary screen sharing over the internet, so that I can remotely work in an image running on a machine in your networkâ¦
Sven
Cheers, Andrei
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
$ curl
http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-...
-H "Accept-Encoding: gzip" | gunzip > foo.mcz % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 3307 0 3307 0 0 7583 0 --:--:-- --:--:-- --:--:-- 8889
$ file foo.mcz foo.mcz: Zip archive data, at least v2.0 to extract
$ ls -l foo.mcz -rw-r--r-- 1 andrei staff 3451 Mar 21 09:55 foo.mcz
$ unzip -l foo.mcz Archive: foo.mcz Length Date Time Name -------- ---- ---- ---- 18 03-27-11 02:22 package 188 03-27-11 02:22 version 8588 03-27-11 02:22 snapshot/source.st 9014 03-27-11 02:22 snapshot.bin -------- ------- 17808 4 files
-- Mariano http://marianopeck.wordpress.com
Once I have a problem loading something from SS3 which was a piece of source code with non-utf8 characters (WideString). Could it be possible you have some non-utf characters in the source of the package you are loading?
I will check, however it happes for a lot of packages. Some work, and some do not work. @Sven I have a linux installation on virtual box where I could reproduce this problem. I can give you access to it.
On Thu, Mar 21, 2013 at 10:08 AM, Sven Van Caekenberghe <sven@stfx.eu> wrote:
Andrei,
On 21 Mar 2013, at 13:28, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
Hi Sven,
I tried all the command from your previous mail and the results are the same (output bellow).
Thanks for the feedback.
The strange thing is that I can download other files from smalltalkhub without problems.
What do you mean, that it only fails for that particular mcz file from StHub in Pharo, but that others are OK ? That would be very disturbing. Can you give an example of a call that does work, with the Transcript output, like
ZnClient new logToTranscript; setAcceptEncodingGzip; get: 'http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-...'; response.
2013-03-20 23:17:17 995343 I Wrote a ZnRequest(GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz) 2013-03-20 23:17:17 995343 D Sent headers User-Agent: Zinc HTTP Components 1.0 Accept-Encoding: gzip Host: www.smalltalkhub.com Accept: */*
2013-03-20 23:17:17 995343 I Read a ZnResponse(200 OK application/x-monticello 3451B) 2013-03-20 23:17:17 995343 D Received headers Date: Wed, 20 Mar 2013 22:17:18 GMT Content-Encoding: gzip Transfer-Encoding: chunked Content-Length: 3451 Vary: Accept-Encoding Server: KomHttpServer/7.1.3 (unix) Content-Type: application/x-monticello
2013-03-20 23:17:17 995343 T GET /mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-Tests-AndreiChis.1.mcz 200 3451B 272ms
A short summary:
ZnEntityReader>>#readEntity calls ZnEntityReader>>#readEntityFromStream which does 'GZipReadStream on: stream', after which 'readFrom:usingType:andLength:' is called. In a wrong call, 'GZipReadStream on: stream' always throws ConnectionClosed. This is handled in ZnClient>>executeWithRetriesRemaining: which keeps retrying until retryCount is 0. On the other hand for some files 'GZipReadStream on: stream' returns correctly, no exception is raised and it works ok.
The exception is thrown in Socket>>waitForDataFor:ifClosed:ifTimedOut: because Socket>>primSocketConnectionStatus: returns 3 instead of 2. [(Time millisecondsSince: startTime) < msecsDelta] whileTrue: [ "here 'self primSocketConnectionStatus: socketHandle' is 2" (self primSocketReceiveDataAvailable: socketHandle) ifTrue: [Transcript crShow: ' hasData'. ^self]. "here 'self primSocketConnectionStatus: socketHandle' is 3, if there is no more content to be read so 'self isConnected' will be false." self isConnected ifFalse: [Transcript crShow: ' notConnected'.^closedBlock value]. self readSemaphore waitTimeoutMSecs: (msecsDelta - (Time millisecondsSince: startTime) max: 0). ].
That fact that this exception is raised during the call to 'GZipReadStream on: stream' seem to be the problem, as this does not allow readFrom: stream usingType: self contentType andLength:
I hope this makes sense.
We probably do not have to look in the socket[stream] layer, the first place to look is in ZnEntityReader, more specifically: what was the situation wrt headers before it starts reading the body, what decisions were taken, and how far was/is it in the reading process.
I can try to dig more into it tomorrow. If you want me to look at other things let me know.
I am wondering whether we could set some temporary screen sharing over the internet, so that I can remotely work in an image running on a machine in your networkâ¦
Sven
Cheers, Andrei
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
$ curl http://www.smalltalkhub.com/mc/AndreiChis/AnnouncerCentricDebugger/main/ACD-... -H "Accept-Encoding: gzip" | gunzip > foo.mcz % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 3307 0 3307 0 0 7583 0 --:--:-- --:--:-- --:--:-- 8889
$ file foo.mcz foo.mcz: Zip archive data, at least v2.0 to extract
$ ls -l foo.mcz -rw-r--r-- 1 andrei staff 3451 Mar 21 09:55 foo.mcz
$ unzip -l foo.mcz Archive: foo.mcz Length Date Time Name -------- ---- ---- ---- 18 03-27-11 02:22 package 188 03-27-11 02:22 version 8588 03-27-11 02:22 snapshot/source.st 9014 03-27-11 02:22 snapshot.bin -------- ------- 17808 4 files
-- Mariano http://marianopeck.wordpress.com
On 21 Mar 2013, at 14:37, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
I will check, however it happes for a lot of packages. Some work, and some do not work.
Strange, I don't think it has to do with the contents, the MC unzipping has not yet even happened. Maybe the size is an element (chunking, buffering).
@Sven I have a linux installation on virtual box where I could reproduce this problem. I can give you access to it.
OK, continuing off list. Sven
On 21 Mar 2013, at 14:52, Sven Van Caekenberghe <sven@stfx.eu> wrote:
On 21 Mar 2013, at 14:37, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
I will check, however it happes for a lot of packages. Some work, and some do not work.
Strange, I don't think it has to do with the contents, the MC unzipping has not yet even happened. Maybe the size is an element (chunking, buffering).
@Sven I have a linux installation on virtual box where I could reproduce this problem. I can give you access to it.
OK, continuing off list.
Sven
Andrei was very helpful in giving me remote access to a machine with a Pharo 2.0 image running inside their network, so that I could have a look at his problem myself - Thanks Andrei ! I think I finally found the cause of this mysterious bug. The bug only appears when ZnEntityReader>>#readEntityFromStream needs to read a GZIP compressed response without an explicit Content-Length (so that it has to read up to end - pretty rare, apparently more common in the case of certain proxies) for a total size less than 65536 bytes (that is why it didn't happen on all cases ;-). In these particular circumstances, a GZipReadStream was created directly on top of a raw SocketStream, which immediately sends a #next: 65536 to the SocketStream. Which fails with a ConnectionClosed instead of returning just the available bytes (like #upToEnd). The fix depends on the question which method is actually wrong, the subject of my next mail ;-) Sven -- Sven Van Caekenberghe http://stfx.eu Smalltalk is the Red Pill
On Thu, Mar 21, 2013 at 4:47 PM, Sven Van Caekenberghe <sven@stfx.eu> wrote:
On 21 Mar 2013, at 14:52, Sven Van Caekenberghe <sven@stfx.eu> wrote:
On 21 Mar 2013, at 14:37, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
I will check, however it happes for a lot of packages. Some work, and some do not work.
Strange, I don't think it has to do with the contents, the MC unzipping has not yet even happened. Maybe the size is an element (chunking, buffering).
@Sven I have a linux installation on virtual box where I could reproduce this problem. I can give you access to it.
OK, continuing off list.
Sven
Andrei was very helpful in giving me remote access to a machine with a Pharo 2.0 image running inside their network, so that I could have a look at his problem myself - Thanks Andrei !
I think I finally found the cause of this mysterious bug.
The bug only appears when ZnEntityReader>>#readEntityFromStream needs to read a GZIP compressed response without an explicit Content-Length (so that it has to read up to end - pretty rare, apparently more common in the case of certain proxies) for a total size less than 65536 bytes (that is why it didn't happen on all cases ;-).
In these particular circumstances, a GZipReadStream was created directly on top of a raw SocketStream, which immediately sends a #next: 65536 to the SocketStream. Which fails with a ConnectionClosed instead of returning just the available bytes (like #upToEnd).
The fix depends on the question which method is actually wrong, the subject of my next mail ;-)
wow....what a great catch. Thanks Sven for all your hard and excellent work!!!
Sven
-- Sven Van Caekenberghe http://stfx.eu Smalltalk is the Red Pill
-- Mariano http://marianopeck.wordpress.com
Thanks for taking the time to look into this. Cheers, Andrei On Thu, Mar 21, 2013 at 8:47 PM, Sven Van Caekenberghe <sven@stfx.eu> wrote:
On 21 Mar 2013, at 14:52, Sven Van Caekenberghe <sven@stfx.eu> wrote:
On 21 Mar 2013, at 14:37, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
I will check, however it happes for a lot of packages. Some work, and some do not work.
Strange, I don't think it has to do with the contents, the MC unzipping has not yet even happened. Maybe the size is an element (chunking, buffering).
@Sven I have a linux installation on virtual box where I could reproduce this problem. I can give you access to it.
OK, continuing off list.
Sven
Andrei was very helpful in giving me remote access to a machine with a Pharo 2.0 image running inside their network, so that I could have a look at his problem myself - Thanks Andrei !
I think I finally found the cause of this mysterious bug.
The bug only appears when ZnEntityReader>>#readEntityFromStream needs to read a GZIP compressed response without an explicit Content-Length (so that it has to read up to end - pretty rare, apparently more common in the case of certain proxies) for a total size less than 65536 bytes (that is why it didn't happen on all cases ;-).
In these particular circumstances, a GZipReadStream was created directly on top of a raw SocketStream, which immediately sends a #next: 65536 to the SocketStream. Which fails with a ConnectionClosed instead of returning just the available bytes (like #upToEnd).
The fix depends on the question which method is actually wrong, the subject of my next mail ;-)
Sven
-- Sven Van Caekenberghe http://stfx.eu Smalltalk is the Red Pill
On 2013-03-21, at 20:47, Sven Van Caekenberghe <sven@stfx.eu> wrote:
On 21 Mar 2013, at 14:52, Sven Van Caekenberghe <sven@stfx.eu> wrote:
On 21 Mar 2013, at 14:37, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
I will check, however it happes for a lot of packages. Some work, and some do not work.
Strange, I don't think it has to do with the contents, the MC unzipping has not yet even happened. Maybe the size is an element (chunking, buffering).
@Sven I have a linux installation on virtual box where I could reproduce this problem. I can give you access to it.
OK, continuing off list.
Sven
Andrei was very helpful in giving me remote access to a machine with a Pharo 2.0 image running inside their network, so that I could have a look at his problem myself - Thanks Andrei !
I think I finally found the cause of this mysterious bug.
The bug only appears when ZnEntityReader>>#readEntityFromStream needs to read a GZIP compressed response without an explicit Content-Length (so that it has to read up to end - pretty rare, apparently more common in the case of certain proxies) for a total size less than 65536 bytes (that is why it didn't happen on all cases ;-).
yes I think that's how far I came as well :)
In these particular circumstances, a GZipReadStream was created directly on top of a raw SocketStream, which immediately sends a #next: 65536 to the SocketStream. Which fails with a ConnectionClosed instead of returning just the available bytes (like #upToEnd).
The fix depends on the question which method is actually wrong, the subject of my next mail ;-)
awesome! thanks for the nailing that one down! :)
On 21 Mar 2013, at 22:20, Camillo Bruni <camillobruni@gmail.com> wrote:
On 2013-03-21, at 20:47, Sven Van Caekenberghe <sven@stfx.eu> wrote:
On 21 Mar 2013, at 14:52, Sven Van Caekenberghe <sven@stfx.eu> wrote:
On 21 Mar 2013, at 14:37, Andrei Vasile Chis <chisvasileandrei@gmail.com> wrote:
I will check, however it happes for a lot of packages. Some work, and some do not work.
Strange, I don't think it has to do with the contents, the MC unzipping has not yet even happened. Maybe the size is an element (chunking, buffering).
@Sven I have a linux installation on virtual box where I could reproduce this problem. I can give you access to it.
OK, continuing off list.
Sven
Andrei was very helpful in giving me remote access to a machine with a Pharo 2.0 image running inside their network, so that I could have a look at his problem myself - Thanks Andrei !
I think I finally found the cause of this mysterious bug.
The bug only appears when ZnEntityReader>>#readEntityFromStream needs to read a GZIP compressed response without an explicit Content-Length (so that it has to read up to end - pretty rare, apparently more common in the case of certain proxies) for a total size less than 65536 bytes (that is why it didn't happen on all cases ;-).
yes I think that's how far I came as well :)
Sure, you and I were looking at the same spot before, but actually being in the debugger made all the difference. BTW, AFAIK it was Andrei who figured out that proceeding from the exception actually produced a correct result. I really had to 'see' this to believe it. And even then it took some quiet thinking to understand the issue.
In these particular circumstances, a GZipReadStream was created directly on top of a raw SocketStream, which immediately sends a #next: 65536 to the SocketStream. Which fails with a ConnectionClosed instead of returning just the available bytes (like #upToEnd).
The fix depends on the question which method is actually wrong, the subject of my next mail ;-)
awesome! thanks for the nailing that one down! :)
Andrei we will introduce your debugger model in 3.0a. It is ok? Stef
participants (5)
-
Andrei Vasile Chis -
Camillo Bruni -
Mariano Martinez Peck -
stephane ducasse -
Sven Van Caekenberghe