Not consistently, but once every 10 tries or so, I get the following backtrace which does not seem to originate in my own code:
Can not modify the buffer right now, there are active subbuffers. -:1: _static_modules._Stdio()->Buffer(0 bytes, read=[..-1] data=[0..-1] free=[0.. 5300] allocated (read only))->add("\f\0\0n\3\0\35 \237{å\32B«=B/ûÓ\2"DmøkFñ 3\35¤\3\37Ò\214+ÜÔ*\4\3\0F0D\2 =Í3]r¿\20CN\222²`ÞG"Ы·\23aÆ\r\237{q)Ùß\t\ 206w(\2 {\23$Ò\4vì\b\227ú\31n\24xÈ¢M\v8d F\1/z\211\vÈx¹ï\222") /usr/local/pike/8.1.13/lib/modules/SSL.pmod/Connection.pike:1051: SSL.ClientConnection(handshaking)->got_data("\26\3\3\0;\2\0\u00007\3\3\ÿP¹\ 17êlU:b5ñwÖäO»àz£eæ(§DOWNGRD\1\0À+\0\0\17ÿ\1\0\1\0\0\v\0\2\1\0\0#\0\0\26\3\3 \r8\v\0\r4\0\r1\0\bË0\202\bÇ0\202\a¯ \3\2\1\2\2\209Î\222 tü½:O5Øj\21ö\rh0\r\ 6\t*\206H\206÷\r\1\1\v\5\u00000T1\v0\t\6\3U\4\6\23\2US1\u001e0\34\6\3"+[3389 ]+"\206w(\2 {\23$Ò\4vì\b\227ú\31n\24xÈ¢M\v8d F\1/z\211\vÈx¹ï\222\26\3\3\0\4\ 16\0\0\0") /usr/local/pike/8.1.13/lib/modules/SSL.pmod/File.pike:1985: SSL.File(Stdio.File("socket", "172.217.20.106:443", 777 /* fd=43 */), SSL.Cl ientConnection(handshaking))->ssl_read_callback(Stdio.File("socket", "172.21 7.20.106:443", 777 /* fd=43 */),"\26\3\3\0;\2\0\u00007\3\3\ÿP¹\17êlU:b5ñwÖä O»àz£eæ(§DOWNGRD\1\0À+\0\0\17ÿ\1\0\1\0\0\v\0\2\1\0\0#\0\0\26\3\3\r8\v\0\r4\0 \r1\0\bË0\202\bÇ0\202\a¯ \3\2\1\2\2\209Î\222 tü½"+[3448]+"ú\31n\24xÈ¢M\v8d F \1/z\211\vÈx¹ï\222\26\3\3\0\4\16\0\0\0") /usr/local/pike/8.1.13/lib/modules/Stdio.pmod/module.pmod:1165: Stdio.File("socket", "172.217.20.106:443", 777 /* fd=43 */)->__stdio_read_ca llback() -:1: Pike.Backend(0)->`()(3600.0) Concurrent.Promise(pending,0): Promise broken. /usr/local/pike/8.1.13/lib/modules/Concurrent.pmod:1176: unknown function() -:1: _static_modules._Stdio()->Buffer(0 bytes, read=[..1279] data=[1280..1279] fr ee=[1280..0] subbuffer)->read_int8() /usr/local/pike/8.1.13/lib/modules/Standards.pmod/ASN1.pmod/Decode.pmod:68: Standards.ASN1.Decode.read_identifier(_static_modules._Stdio()->Buffer(0 byt es, read=[..1279] data=[1280..1279] free=[1280..0] subbuffer)) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/ASN1.pmod/Decode.pmod:100: Standards.ASN1.Decode.der_decode(@0=_static_modules._Stdio()->Buffer(0 bytes , read=[..1279] data=[1280..1279] free=[1280..0] subbuffer),mapping[23]) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/ASN1.pmod/Decode.pmod:157: Standards.ASN1.Decode.der_decode(@0,@1=mapping[23]) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/ASN1.pmod/Decode.pmod:245: Standards.ASN1.Decode.secure_der_decode("0\202\5\0\202\20*.googleapis.com\20 2\24*.clients6.google.ae\202\24*.clients6.google.at\202\24*.clients6.google. be\202\24*.clients6.google.ca\202\24*.clients6.google.ch\202\24*.clients6"+[ 1094]+"is.com\202\26cloudendpointsapis.com\202\16googleapis.com",@1) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:703: Standards.X509.TBSCertificate(([ /* 5 elements */ "algorithm": Standards.ASN1.Types.Sequence(({ /* 2 elements */ Standards.ASN1.Types.Identifier(1.2.840.113549.1.1.11), Standards.ASN1.Types.Null() })), "issuer": ([ /* 3 elements */ "commonName": "Google Internet Authority G3", "countryName": "US", "organizationName": "Google Trust Services" ]), "serial": Gmp.mpz(76838582857112318721873235160560176488), "subject": ([ /* 5 elements */ "commonName": "*.googleapis.com", "countryName": "US", "localityName": "Mountain View", "organizationName": "Google LLC", "stateOrProvinceName": "California" ]), "version": 3 ]))->`raw_extensions=(Standards.ASN1.Types.Sequence(...)) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:938: Standards.X509.TBSCertificate(([ /* 5 elements */ "algorithm": Standards.ASN1.Types.Sequence(({ /* 2 elements */ Standards.ASN1.Types.Identifier(1.2.840.113549.1.1.11), Standards.ASN1.Types.Null() })), "issuer": ([ /* 3 elements */ "commonName": "Google Internet Authority G3", "countryName": "US", "organizationName": "Google Trust Services" ]), "serial": Gmp.mpz(76838582857112318721873235160560176488), "subject": ([ /* 5 elements */ "commonName": "*.googleapis.com", "countryName": "US", "localityName": "Mountain View", "organizationName": "Google LLC", "stateOrProvinceName": "California" ]), "version": 3 ]))->init(Standards.ASN1.Types.Sequence(...)) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:763: Standards.X509.TBSCertificate(([ /* 5 elements */ "algorithm": Standards.ASN1.Types.Sequence(({ /* 2 elements */ Standards.ASN1.Types.Identifier(1.2.840.113549.1.1.11), Standards.ASN1.Types.Null() })), "issuer": ([ /* 3 elements */ "commonName": "Google Internet Authority G3", "countryName": "US", "organizationName": "Google Trust Services" ]), "serial": Gmp.mpz(76838582857112318721873235160560176488), "subject": ([ /* 5 elements */ "commonName": "*.googleapis.com", "countryName": "US", "localityName": "Mountain View", "organizationName": "Google LLC", "stateOrProvinceName": "California" ]), "version": 3 ]))->create(@2=Standards.ASN1.Types.Sequence(...)) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:329: Standards.X509.TBSCertificate() /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:1448: Standards.X509.decode_certificate(Standards.PKCS.Signature.Signed(...)) /usr/local/pike/8.1.13/lib/modules/SSL.pmod/Connection.pike:283: SSL.ClientConnection(handshaking)->verify_certificate_chain(({"0\202\bÇ0\202 \a¯ \3\2\1\2\2\209Î\222 tü½:O5Øj\21ö\rh0\r\6\t*\206H\206÷\r\1\1\v\5\u00000T1 \v0\t\6\3U\4\6\23\2US1\u001e0\34\6\3U\4\n"+[2160]+"É\vèÍ|ÂPD\201\220.R#Z³\23 7iG(#ç","0\202\4\0\202\3D \3\2\1\2\2\r\1ã©0\34ür\68?\232S\u001d0\r\6\t*\206 H\206÷\r\1\1\v\5\u00000L1 0\36\6\3U\4\v\23\27GlobalSign Roo"+[1029]+"\234@èÖ Usº<ß\220Ë\0[!\21gÂí2\36Þ"})) /usr/local/pike/8.1.13/lib/modules/SSL.pmod/Connection.pike:372: SSL.ClientConnection(handshaking)->handle_certificates(SSL.Buffer(0 bytes, r ead=[..3379] data=[3380..3379] free=[3380..3480] allocated)) /usr/local/pike/8.1.13/lib/modules/SSL.pmod/ClientConnection.pike:876: SSL.ClientConnection(handshaking)->handle_handshake(11,@3=SSL.Buffer(0 bytes , read=[..3379] data=[3380..3379] free=[3380..3480] allocated),_static_modul es._Stdio()->Buffer(3384 bytes, read=[..-1] data=[0..3383] free=[3384..0] su bbuffer)) /usr/local/pike/8.1.13/lib/modules/SSL.pmod/Connection.pike:1070: SSL.ClientConnection(handshaking)->got_data("\26\3\3\0;\2\0\u00007\3\3\ÿP¹\ 17êlU:b5ñwÖäO»àz£eæ(§DOWNGRD\1\0À+\0\0\17ÿ\1\0\1\0\0\v\0\2\1\0\0#\0\0\26\3\3 \r8\v\0\r4\0\r1\0\bË0\202\bÇ0\202\a¯ \3\2\1\2\2\209Î\222 tü½:O5Øj\21ö\rh0\r\ 6\t*\206H\206÷\r\1\1\v\5\u00000T1\v0\t\6\3U\4\6\23\2US1\u001e0\34\6\3"+[3389 ]+"\206w(\2 {\23$Ò\4vì\b\227ú\31n\24xÈ¢M\v8d F\1/z\211\vÈx¹ï\222\26\3\3\0\4\ 16\0\0\0") /usr/local/pike/8.1.13/lib/modules/SSL.pmod/File.pike:1985: SSL.File(Stdio.File("socket", "172.217.20.106:443", 777 /* fd=43 */), SSL.Cl ientConnection(handshaking))->ssl_read_callback(Stdio.File("socket", "172.21 7.20.106:443", 777 /* fd=43 */),"\26\3\3\0;\2\0\u00007\3\3\ÿP¹\17êlU:b5ñwÖä O»àz£eæ(§DOWNGRD\1\0À+\0\0\17ÿ\1\0\1\0\0\v\0\2\1\0\0#\0\0\26\3\3\r8\v\0\r4\0 \r1\0\bË0\202\bÇ0\202\a¯ \3\2\1\2\2\209Î\222 tü½"+[3448]+"ú\31n\24xÈ¢M\v8d F \1/z\211\vÈx¹ï\222\26\3\3\0\4\16\0\0\0") /usr/local/pike/8.1.13/lib/modules/Stdio.pmod/module.pmod:1165: Stdio.File("socket", "172.217.20.106:443", 777 /* fd=43 */)->__stdio_read_ca llback() -:1: Pike.Backend(0)->`()(3600.0)
Stephen R. van den Berg wrote:
Not consistently, but once every 10 tries or so, I get the following backtrace which does not seem to originate in my own code:
Might it be triggered by an HTTP keep-alive session terminating?
My normal program logic works fine, so all API-sessions I have with Google seem to work within limits. It mostly clutters the logs and undoubtedly is the cause of some spurious network traffic nobody asked for.
Stephen R. van den Berg wrote:
Not consistently, but once every 10 tries or so, I get the following backtrace which does not seem to originate in my own code:
Might it be triggered by an HTTP keep-alive session terminating?
My normal program logic works fine, so all API-sessions I have with Google seem to work within limits. It mostly clutters the logs and undoubtedly is the cause of some spurious network traffic nobody asked for.
I suspect that the SSL.Buffer created on line ~1057 of Connection.pike for some reason hasn't been destructed. The most likely cause for this is probably that it is stuck as an argument in a backtrace for the call of handle_handshake() a few lines further down.
Try running your test case with -DSSL3_DEBUG and see if you can trigger the issue and if you get messages about handshaking errors before.
You can also try adding an inherit of Builtin.DestructImmediate (this class ought to be moved to Pike.DestructImmediate) to SSL.Buffer, and see if this solves the issue.
/grubba
Henrik Grubbstr?m (Lysator) @ Pike (-) developers forum wrote:
Try running your test case with -DSSL3_DEBUG and see if you can trigger the issue and if you get messages about handshaking errors before.
You can also try adding an inherit of Builtin.DestructImmediate (this class ought to be moved to Pike.DestructImmediate) to SSL.Buffer, and see if this solves the issue.
Haven't tried any of those (yet). I merely recompiled with your most recent commits in it, and so far, the spurious exceptions seem to be gone.
Stephen R. van den Berg wrote:
Henrik Grubbstr?m (Lysator) @ Pike (-) developers forum wrote:
Try running your test case with -DSSL3_DEBUG and see if you can trigger the issue and if you get messages about handshaking errors before.
You can also try adding an inherit of Builtin.DestructImmediate (this class ought to be moved to Pike.DestructImmediate) to SSL.Buffer, and see if this solves the issue.
Haven't tried any of those (yet). I merely recompiled with your most recent commits in it, and so far, the spurious exceptions seem to be gone.
Sorry, it still happens, but the frequency with which it happens has been reduced, it seems:
Concurrent.Promise(pending,0): Promise broken. /usr/local/pike/8.1.13/lib/modules/Concurrent.pmod:1176: unknown function() /usr/local/pike/8.1.13/lib/modules/Standards.pmod/ASN1.pmod/Types.pmod:907: Standards.ASN1.Types.UTC("190820141200Z")->init() /usr/local/pike/8.1.13/lib/modules/Standards.pmod/ASN1.pmod/Types.pmod:151: Standards.ASN1.Types.UTC("190820141200Z")->create(Second(Tue 20 Aug 2019 14: 12:00 UTC)) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/ASN1.pmod/Types.pmod:900: Standards.ASN1.Types.UTC() /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:477: Standards.X509.TBSCertificate(([ /* 5 elements */ "algorithm": Standards.ASN1.Types.Sequence(({ /* 2 elements */ Standards.ASN1.Types.Identifier(1.2.840.113549.1.1.11), Standards.ASN1.Types.Null() })), "issuer": ([ /* 3 elements */ "commonName": "Google Internet Authority G3", "countryName": "US", "organizationName": "Google Trust Services" ]), "serial": Gmp.mpz(74215313534289496774554095895205298722), "subject": ([ /* 5 elements */ "commonName": "*.googleapis.com", "countryName": "US", "localityName": "Mountain View", "organizationName": "Google LLC", "stateOrProvinceName": "California" ]), "version": 3 ]))->time_object(1566310320) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:497: Standards.X509.TBSCertificate(([ /* 5 elements */ "algorithm": Standards.ASN1.Types.Sequence(({ /* 2 elements */ Standards.ASN1.Types.Identifier(1.2.840.113549.1.1.11), Standards.ASN1.Types.Null() })), "issuer": ([ /* 3 elements */ "commonName": "Google Internet Authority G3", "countryName": "US", "organizationName": "Google Trust Services" ]), "serial": Gmp.mpz(74215313534289496774554095895205298722), "subject": ([ /* 5 elements */ "commonName": "*.googleapis.com", "countryName": "US", "localityName": "Mountain View", "organizationName": "Google LLC", "stateOrProvinceName": "California" ]), "version": 3 ]))->`not_after=(1566310320) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:893: Standards.X509.TBSCertificate(([ /* 5 elements */ "algorithm": Standards.ASN1.Types.Sequence(({ /* 2 elements */ Standards.ASN1.Types.Identifier(1.2.840.113549.1.1.11), Standards.ASN1.Types.Null() })), "issuer": ([ /* 3 elements */ "commonName": "Google Internet Authority G3", "countryName": "US", "organizationName": "Google Trust Services" ]), "serial": Gmp.mpz(74215313534289496774554095895205298722), "subject": ([ /* 5 elements */ "commonName": "*.googleapis.com", "countryName": "US", "localityName": "Mountain View", "organizationName": "Google LLC", "stateOrProvinceName": "California" ]), "version": 3 ]))->init(Standards.ASN1.Types.Sequence(...)) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:763: Standards.X509.TBSCertificate(([ /* 5 elements */ "algorithm": Standards.ASN1.Types.Sequence(({ /* 2 elements */ Standards.ASN1.Types.Identifier(1.2.840.113549.1.1.11), Standards.ASN1.Types.Null() })), "issuer": ([ /* 3 elements */ "commonName": "Google Internet Authority G3", "countryName": "US", "organizationName": "Google Trust Services" ]), "serial": Gmp.mpz(74215313534289496774554095895205298722), "subject": ([ /* 5 elements */ "commonName": "*.googleapis.com", "countryName": "US", "localityName": "Mountain View", "organizationName": "Google LLC", "stateOrProvinceName": "California" ]), "version": 3 ]))->create(@0=Standards.ASN1.Types.Sequence(...)) /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:329: Standards.X509.TBSCertificate() /usr/local/pike/8.1.13/lib/modules/Standards.pmod/X509.pmod:1448: Standards.X509.decode_certificate(Standards.PKCS.Signature.Signed(...)) /usr/local/pike/8.1.13/lib/modules/SSL.pmod/Connection.pike:283: SSL.ClientConnection(handshaking)->verify_certificate_chain(({"0\202\bÇ0\202 \a¯ \3\2\1\2\2\u00107ÕYv§\234\227Y\230pÈ\220L\216Â"0\r\6\t*\206H\206÷\r\1\1 \v\5\u00000T1\v0\t\6\3U\4\6\23\2US1\u001e0\34\6\3U\4\n"+[2160]+"\200\177¹Òú\ \25Ùbµª;\W\3Væú\31õ¡","0\202\4\0\202\3D \3\2\1\2\2\r\1ã©0\34ür\68?\232S\u 001d0\r\6\t*\206H\206÷\r\1\1\v\5\u00000L1 0\36\6\3U\4\v\23\27GlobalSign Roo" +[1029]+"\234@èÖUsº<ß\220Ë\0[!\21gÂí2\36Þ"})) /usr/local/pike/8.1.13/lib/modules/SSL.pmod/Connection.pike:372: SSL.ClientConnection(handshaking)->handle_certificates(SSL.Buffer()) /usr/local/pike/8.1.13/lib/modules/SSL.pmod/ClientConnection.pike:876: SSL.ClientConnection(handshaking)->handle_handshake(11,SSL.Buffer(),_static_ modules._Stdio()->Buffer()) /usr/local/pike/8.1.13/lib/modules/SSL.pmod/Connection.pike:1070: SSL.ClientConnection(handshaking)->got_data("\26\3\3\0;\2\0\u00007\3\3]\1\27 w2.ZP©\aõ\222XÁ\210ÜØc\224í~Ö\\rDOWNGRD\1\0À+\0\0\17ÿ\1\0\1\0\0\v\0\2\1\0\0 #\0\0\26\3\3\r8\v\0\r4\0\r1\0\bË0\202\bÇ0\202\a¯ \3\2\1\2\2\u00107ÕYv§\234\2 27Y\230pÈ\220L\216Â"0\r\6\t*\206H\206÷\r\1\1\v\5\u00000T1\v0\t\6\3U\4\6\23\ 2US1\u001e0\34\6\3"+[3391]+"q¯\2!\0ü\234[ÛZ¨V\35·åï\230\3cÿ<J\221æ÷\201÷ã\16 ð9\26¯ýu\201\217\26\3\3\0\4\16\0\0\0") /usr/local/pike/8.1.13/lib/modules/SSL.pmod/File.pike:1985: SSL.File(Stdio.File("socket", "172.217.168.234:443", 777 /* fd=116 */), SSL. ClientConnection(handshaking))->ssl_read_callback(Stdio.File("socket", "172. 217.168.234:443", 777 /* fd=116 */),"\26\3\3\0;\2\0\u00007\3\3]\1\27w2.ZP©\a õ\222XÁ\210ÜØc\224í~Ö\\rDOWNGRD\1\0À+\0\0\17ÿ\1\0\1\0\0\v\0\2\1\0\0#\0\0\26 \3\3\r8\v\0\r4\0\r1\0\bË0\202\bÇ0\202\a¯ \3\2\1\2\2\u00107ÕYv§\234"+[3452]+" ï\230\3cÿ<J\221æ÷\201÷ã\16ð9\26¯ýu\201\217\26\3\3\0\4\16\0\0\0") /usr/local/pike/8.1.13/lib/modules/Stdio.pmod/module.pmod:1165: Stdio.File("socket", "172.217.168.234:443", 777 /* fd=116 */)->__stdio_read_ callback() -:1: Pike.Backend(0)->`()(3600.0) Concurrent.Promise(pending,0): Promise broken.
pike-devel@lists.lysator.liu.se
-
Henrik Grubbstr�m (Lysator) ＠ Pike (-) developers forum -
Stephen R. van den Berg