Bug 466335 - got two '500's from TSA but succeeded on third
Summary: got two '500's from TSA but succeeded on third
Status: RESOLVED INVALID
Alias: None
Product: CBI
Classification: Technology
Component: signing-service (show other bugs)
Version: 1.1.1   Edit
Hardware: PC Linux
: P3 minor (vote)
Target Milestone: ---   Edit
Assignee: CBI Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords: info
Depends on:
Blocks:
 
Reported: 2015-05-04 13:11 EDT by David Williams CLA
Modified: 2015-05-05 02:53 EDT (History)
2 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description David Williams CLA 2015-05-04 13:11:32 EDT
This is not really a bug ... but, perhaps an early warning of one? Or, maybe all is well, and things are working just as designed (for which you have my congratulations on having some resiliency built-in to the signing service). 

I just thought you might want to check logs, or check queues for approximately 1 PM Eastern, to see if anything was "real busy" ... or ... most likely, TSA really did just burp for a few minutes and your high quality code dealt with it just fine, as it was designed to "retry" a few times. 

= = = = = =


[INFO] Signing of inner jars for org.eclipse.help:org.eclipse.help.base:eclipse-plugin:4.0.300-SNAPSHOT is disabled, inner jars will not be signed.
[INFO] Signed org.eclipse.help:org.eclipse.help.base:eclipse-plugin:4.0.300-SNAPSHOT in 1 seconds.
[INFO] Signing of inner jars for org.eclipse.help:org.eclipse.help.base:java-source:sources:4.0.300-SNAPSHOT is disabled, inner jars will not be signed.
[DEBUG] org.apache.http.NoHttpResponseException: Server failed with  updating: META-INF/MANIFEST.MF
jarsigner: unable to sign jar: no response from the Timestamping Authority. When connecting from behind a firewall an HTTP or HTTPS proxy may need to be specified. Supply the following options to jarsigner:
  -J-Dhttp.proxyHost=<hostname>
  -J-Dhttp.proxyPort=<portnumber>
or
  -J-Dhttps.proxyHost=<hostname>
  -J-Dhttps.proxyPort=<portnumber>


Error 500: Codesign tool exit status: 1.
[INFO] Failed to sign org.eclipse.help.base-4.0.300-SNAPSHOT-sources.jar with server. Retrying...
[DEBUG] org.apache.http.NoHttpResponseException: Server failed with  updating: META-INF/MANIFEST.MF
jarsigner: unable to sign jar: java.net.UnknownHostException: timestamp.geotrust.com


Error 500: Codesign tool exit status: 1.
[INFO] Failed to sign org.eclipse.help.base-4.0.300-SNAPSHOT-sources.jar with server. Retrying...
[INFO] Signed org.eclipse.help:org.eclipse.help.base:java-source:sources:4.0.300-SNAPSHOT in 108 seconds.
[INFO]
Comment 1 Denis Roy CLA 2015-05-04 13:36:17 EDT
(In reply to David Williams from comment #0)
> I just thought you might want to check logs, or check queues for
> approximately 1 PM Eastern,

For yesterday (Sunday March 3) I presume?



Are there timestamps for this?  I have a hard time believing it would a) receive no response then b) cannot resolve the hostname 'timestamp.geotrust.com' to an IP address.


> [DEBUG] org.apache.http.NoHttpResponseException: Server failed with 
> updating: META-INF/MANIFEST.MF
> jarsigner: unable to sign jar: no response from the Timestamping Authority.


> jarsigner: unable to sign jar: java.net.UnknownHostException:
> timestamp.geotrust.com
Comment 2 David Williams CLA 2015-05-04 13:49:02 EDT
No, it was from today, approximately 1 PM ... I'll look at larger log to see if time stamp is near by ...
Comment 3 David Williams CLA 2015-05-04 14:04:39 EDT
Only time stamp in log I could find was at the beginning, where my scripts write: 

Starting ./mb4I.sh at 20150504-1224

If I knew how, I guess I could look at the jars signature timestamp it got on the third try for something more exact. 

The (test) build is still running, but if you wanted to try to look yourself, the log I was looking at, when I saw this message fly by, is at 

/opt/public/eclipse/builds/mb4I.out.log

The jar that was signed (on third try) is, I think the one at 

/opt/public/eclipse/builds/4I/gitCache/eclipse.platform.releng.aggregator/eclipse.platform.ua/org.eclipse.help.base/target/org.eclipse.help.base-4.0.300-SNAPSHOT.jar

I see it's file timestamp is 13:01. 

HTH
Comment 4 David Williams CLA 2015-05-04 14:13:17 EDT
I did open enhancement request 466343 to include a timestamp in error messages. 

(Tycho in general should probably do that ... but ... at least jar signer is "in our control".).
Comment 5 David Williams CLA 2015-05-04 14:30:37 EDT
(In reply to Denis Roy from comment #1)
> Are there timestamps for this?  I have a hard time believing it would a)
> receive no response then b) cannot resolve the hostname
> 'timestamp.geotrust.com' to an IP address.

Maybe a DNS error ... "offline" the first time, then online, but not quite sync'd up? 

For the record, This error message was recently added (I think first by me, then improved by Mikael). Previously, they were "ignored" and would not have been in the log. 

According to the code comments, It appears it is supposed to retry 3 times, with 30 seconds between each re-try. Oddly, though, even that's what the comments say, I do not really see where these values are set "in the code". 

Perhaps Mikael can explain that magic?
Comment 6 Denis Roy CLA 2015-05-04 16:46:38 EDT
I looked at our DNS logs and nothing really jumped out at me.  There's a ton of moving parts here, many of which we don't control, so unless there's something repeatable, I'm not sure what we're looking for, or why.
Comment 7 David Williams CLA 2015-05-04 17:08:14 EDT
Ok, I intended as "FYI", in case it was a "warning" of something. 

But, if not helpful, no need to look at further. It was the only occurrence in that build. I do not routinely look for them, but will only report again if I see a whole lot of them ... or, if even 3 retires can not reach TSA. (which, results in another error message). Again, complements to ?Thanh? for building in the "retries". 

... just trying to be helpful ...
Comment 8 Mikaël Barbero CLA 2015-05-05 02:51:44 EDT
(In reply to David Williams from comment #5)
> According to the code comments, It appears it is supposed to retry 3 times,
> with 30 seconds between each re-try. Oddly, though, even that's what the
> comments say, I do not really see where these values are set "in the code". 
> 
> Perhaps Mikael can explain that magic?

The not-so-magic is here: https://git.eclipse.org/c/cbi/org.eclipse.cbi.maven.plugins.git/tree/eclipse-jarsigner-plugin/src/main/java/org/eclipse/cbi/maven/plugins/jarsigner/SignMojo.java#n331

and the values of retryTimer and retryLimit are set by Maven. The Javadoc taglets are processed @ compile time to create the necessary code. See  https://git.eclipse.org/c/cbi/org.eclipse.cbi.maven.plugins.git/tree/eclipse-jarsigner-plugin/src/main/java/org/eclipse/cbi/maven/plugins/jarsigner/SignMojo.java#n148.
Comment 9 Mikaël Barbero CLA 2015-05-05 02:53:36 EDT
(In reply to David Williams from comment #7)
> Ok, I intended as "FYI", in case it was a "warning" of something. 
> 
> But, if not helpful, no need to look at further. It was the only occurrence
> in that build. I do not routinely look for them, but will only report again
> if I see a whole lot of them ... or, if even 3 retires can not reach TSA.
> (which, results in another error message). Again, complements to ?Thanh? for
> building in the "retries". 
> 
> ... just trying to be helpful ...

I almost finish the refactoring of the maven plugins and I added a lot more logging than what was existing before (along with unit tests). I hope it will help in such case. I plan to submit the reviews by tomorrow evening.