Somewhat resolved -- Re: [Vm-dev] when the vm crashes...
Bob Arning
arning315 at comcast.net
Sun Mar 30 21:21:44 UTC 2014
I've come to understand a bit about why the VM was crashing when making
requests via SqueakSSL. For some sites I could make request after
request with no ill effects. A successful request/response looks like this:
Mar 30 14:05:47 *user*: sqEncryptSSL: Encrypting 91 bytes
Mar 30 14:05:47 *user*: SqueakSSLWrite: Writing 117 bytes, having 191
free === the encrypted request to be sent
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 2896 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 2896 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 5 bytes, having 2896 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 13168 bytes, having
2891 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 2896 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 2896 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 10277 bytes, having
2896 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 1448 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 1448 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 7381 bytes, having
1448 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 4096 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 4096 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 5933 bytes, having
4096 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 3144 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 3144 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 1837 bytes, having
3144 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 0 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 1307 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 0 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 1307 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 0 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 1307 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 5 bytes, having 1307 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 7488 bytes, having
1302 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 0 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 0 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 6186 bytes, having 0 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 2896 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 2896 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 6186 bytes, having
2896 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 3290 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 3290 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 3290 bytes, having
3290 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 0 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 0 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 5 bytes, having 0 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Input data 0 bytes
Mar 30 14:05:47 *user*: sqDecryptSSL: Decrypting 0 bytes
Mar 30 14:05:47 *user*: SqueakSSLRead: Requesting 5 bytes, having 0 bytes
and this can repeat many times as request after request succeeds.
Other sites would crash the vm after a small number of requests. With
the insertion of enough "String new" calls in the right place, the crash
could almost be guaranteed to occur on the first attempt. A failure
looks like this:
Mar 30 13:54:36 *user* sqEncryptSSL: Encrypting 80 bytes
Mar 30 13:54:36 *user* SqueakSSLWrite: Writing 105 bytes, having 180
free === making our encrypted request
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 1452 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1452 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1452 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1447
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 0 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 4091
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2644 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2644 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2639
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1192 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1192 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1187
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 260 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3836 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3836 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3831
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2384 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2384 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2379
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 932 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 932 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 927
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 520 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3576 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3576 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3571
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2124 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2124 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2119
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 672 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 672 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 667
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 780 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3316 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3316 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3311
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1864 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1864 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1859
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 412 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 412 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 407
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1040 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3056 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3056 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3051
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1604 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1604 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1599
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 152 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 152 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 147
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1300 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2796 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2796 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2791
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1344 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1344 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1339
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 108 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3988 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3988 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3983
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2536 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2536 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2531
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1084 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1084 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1079
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 368 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3728 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3728 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3723
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2276 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2276 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2271
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 824 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 824 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 819
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 628 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3468 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3468 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3463
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2016 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2016 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2011
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 564 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 564 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 559
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 888 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3208 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3208 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3203
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1756 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1756 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1751
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 304 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 304 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 299
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1148 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2948 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2948 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2943
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1496 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1496 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1491
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 44 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 44 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 39 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1408 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2688 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2688 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2683
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1236 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1236 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1231
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 216 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3880 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3880 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3875
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2428 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2428 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2423
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 976 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 976 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 971
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 476 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3620 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3620 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3615
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2168 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2168 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2163
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 716 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 716 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 711
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 736 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3360 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3360 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3355
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1908 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1908 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1903
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 456 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 456 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 451
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 996 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3100 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3100 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3095
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1648 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1648 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1643
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 196 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 196 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 191
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1256 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2840 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2840 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2835
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1388 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1388 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1383
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 64 bytes, having 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4032 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 4032 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 4027
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2580 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2580 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2575
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1128 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1128 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1123
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 324 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3772 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3772 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3767
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2320 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2320 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2315
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 868 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 868 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 863
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 584 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3512 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3512 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3507
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2060 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2060 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2055
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 608 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 608 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 603
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 4096 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 4096 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 844 bytes, having 4096
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3252 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 3252 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 3247
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1800 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1800 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 1795
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 348 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 348 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 343
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 3679 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 3679 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1104 bytes, having 3679
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 2575 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 2575 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1447 bytes, having 2570
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 1123 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 1123 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 1091 bytes, having 1118
bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Input data 0 bytes
Mar 30 13:54:36 *user* sqDecryptSSL: Decrypting 27 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 5 bytes, having 27 bytes
Mar 30 13:54:36 *user* SqueakSSLRead: Requesting 22 bytes, having 22 bytes
data all received now, but what's this:
Mar 30 13:54:36 *user* SqueakSSLWrite: Writing 27 bytes, having 75 free
Mar 30 13:54:36 *user* sqDecryptSSL: SSLRead returned -9805
Mar 30 13:54:36 *user* last object overwritten
errSSLClosedGraceful -9805
The connection closed gracefully.
Available in OS X v10.2 and later.
this is the only SqueakSSLWrite: not immediately following a
sqEncryptSSL, so where did it come from? I don't know, but I do know
it's using the same buffer provided in the last sqEncryptSSL call. The
problem is that this buffer was a method temp and may well have moved or
been gc'd in the interim. My hack was to make the buffer used by encrypt
and connect a permanent one to minimize the chance of movement. Just to
verify, I zeroed this buffer once the request had been sent and checked
it after the response had been received. This is what it looked like:
#[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 21 3
1 0 22 183 80 173 250 155 255 108 25 132 220 40 109 216 134 178 73 243
155 35 75 231 89 0 0 0...
the 27 bytes indicated in the squeakssl log output were inserted in this
buffer at the next output position. Not sure why this extra write
happens where it does or if it happens in other OS configurations, so
the real fix is still a mystery. I think I can live with the global
buffer for my purposes.
Cheers,
Bob
On 3/28/14 1:40 PM, Eliot Miranda wrote:
>
>
>
>
>
>
> On Fri, Mar 28, 2014 at 8:17 AM, Bob Arning <arning315 at comcast.net
> <mailto:arning315 at comcast.net>> wrote:
>
>
> Eliot,
>
> I figured out where the "console" ends up and you are right - is
> was last object overwritten. File attached if it's of any use. My
> testing has proceeded to the point that repeated calls to
> "SqueakSSL google: 'squeak'" work fine, but calls to a very
> similar method connecting to a different host will crash the vm
> after a few iterations.
>
>
> At this point I would switch to gdb, set a breakpoint in error, run
> the reproducible case, then use
>
> call printOop(objectBefore(freeStart))
>
> to find out which object was overwritten. That may be a good enough
> clue to find out where the overwriting is occurring. You can try
>
> call longPrintOop(objectBefore(freeStart))
>
> which may give you more info.
>
>
> Cheers,
> Bob
>
>
> On 3/27/14 1:03 PM, Eliot Miranda wrote:
>>
>>
>>
>> Hi Bob,
>>
>>
>> On Thu, Mar 27, 2014 at 4:33 AM, Bob Arning
>> <arning315 at comcast.net <mailto:arning315 at comcast.net>> wrote:
>>
>>
>> Is there enough information in the attached file to point to
>> a possible cause?
>>
>>
>> Yes. But there should hopefully be the output of error on the
>> console and that would disambiguate between the two possible
>> causes. This is the stack:
>>
>> 2 libsystem_c.dylib 0x9b609bdd abort + 167
>> 3 org.squeak.SqueakAllInOne45 0x000703be error + 94
>> 4 org.squeak.SqueakAllInOne45 0x000d1c4f
>> eeInstantiateSmallClasssizeInBytes + 95
>> 5 org.squeak.SqueakAllInOne45 0x000d31a0
>> createClosureNumArgsnumCopiedstartpc + 80
>> 6 org.squeak.SqueakAllInOne45 0x000c6e69
>> ceClosureCopyDescriptor + 41
>> There are two possible errors in eeInstantiateSmallClasssizeInBytes
>> error("last object overwritten");
>> error("out of memory");
>>
>>
>> The first means that something wrote past the end of an object
>> and this was detected when a new object was allocated, seeing
>> that freeSpace did not contain the pattern expected. This e.g.
>> happens when passing buffer objects to foreign code which writes
>> beyond the object.
>>
>> The second usually means infinite recursion. Looking at the
>> memory map at the end of the error report I think that the error
>> is last object overwritten.
>>
>>
>> Cheers,
>> Bob
>>
>>
>>
>>
>> --
>> best,
>> Eliot
>
>
>
>
>
> --
> best,
> Eliot
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.squeakfoundation.org/pipermail/vm-dev/attachments/20140330/7967523e/attachment-0001.htm
More information about the Vm-dev
mailing list