Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 309871

Summary: signing process needs better logging
Product: Community Reporter: Kim Moir <kim.moir>
Component: ServersAssignee: Eclipse Webmaster <webmaster>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: P3 CC: christian.campo, david_williams
Version: unspecified   
Target Milestone: ---   
Hardware: PC   
OS: Windows XP   
Whiteboard:

Description Kim Moir CLA 2010-04-20 16:27:30 EDT
Today, I sent my bundles to be signed for our integration build.

Since it had problems and caused the build to fail, I happened to be tailing /tmp/jarsigner.  I noticed that many of the jars were not singed with an java.io.IOException.  Here is an example

jarsigner: unable to sign jar: java.io.IOException: DER input not a UTF8 string
SIGNER: asked to sign
/opt/public/download-staging.priv/eclipse/I20100420-0800-out/temp_eclipse-master-I20100420-0800.zip/org.eclipse.core.commands_3.6.0.I20100122-0800.jar
 updating: META-INF/MANIFEST.MF
jarsigner: unable to sign jar: java.io.IOException: DER input not a UTF8 string

It would be nice if there was a log for each signing process that is invoked.  As it is, the signing process just returns unsigned jars in the case of an exception which is less than optimal.  Each time we have unsigned jars in our p2 repository, we have to get our developers to retag them so they are signed in the next build.
Comment 1 Denis Roy CLA 2010-04-27 13:39:34 EDT
(In reply to comment #0)
> It would be nice if there was a log for each signing process that is invoked. 

Since many signing processes can run simultaneously, here's what I suggest:

- we keep everything in a single log file
- we rotate log file every night
- we don't truncate the logfile at the beginning of a job, like we do now
- since every job is based on a queue, we prefix messages in the log with the queue id (ie, pid) _where we can_.

Here is an example.  This is based loosely on a Postfix-style mail log:

2010-04-27 13:35:01 QUEUE: Begin processing queue: 23175
1272389645:droy:/home/data/httpd/download-staging.priv/technology/phoenix/org.eclipse.sdk_3.0.1.jar:mail:/home/data/httpd/download-staging.priv/technology/phoenix
======================= end of (23175) contents
2010-04-27 13:35:01: QUEUE(23175): calling jarprocessor.jar for /home/data/httpd/download-staging.priv/technology/phoenix/org.eclipse.sdk_3.0.1.jar
2010-04-27 13:35:05 SIGNER(23175): asked to sign /opt/public/download-staging.priv/technology/phoenix/org.eclipse.sdk_3.0.1.jar
2010-04-27 13:35:05 SIGNER(23175): Finished signing /opt/public/download-staging.priv/technology/phoenix/org.eclipse.sdk_3.0.1.jar
2010-04-27 13:35:01: QUEUE(23175): Finished processing queue.


Of course, the above log messages could contain messages from another queue should there be two (or more) queues running.  But, like a mail log, you should be able to easily trace what is going on.

You can tail this right now, on build: /tmp/signing/signer.log.
Comment 2 David Williams CLA 2010-04-27 13:52:46 EDT
Sounds adequate to me ... little that I know. One question though, we sometimes like to "snag" a copy of logs (such as this one) and keep with the build results for later checking/confirmation/records ... how large would this file get? Large enough to prohibit copying every build? 

Mostly just curious. Even if possible, not sure we would do this, unless becomes a frequent problem. 

Thanks,
Comment 3 Kim Moir CLA 2010-04-27 15:52:57 EDT
Thanks Denis for setting this up. 

I think you need to adjust the permissions on the log

kmoir@build:~> tail -f /tmp/signing/signer.log
tail: cannot open `/tmp/signing/signer.log' for reading: Permission denied
tail: no files remaining
Comment 4 Denis Roy CLA 2010-04-27 15:55:23 EDT
I knew that.  Just checking if you were paying attention.
Comment 5 Kim Moir CLA 2010-04-27 16:01:28 EDT
I'm always paying attention :-)
Comment 6 Denis Roy CLA 2010-04-27 16:13:57 EDT
> how large would this file get?

It's currently sitting at 13M uncompressed.  It likely contains a lot of irrelevant chit-chat from other signing requests.
Comment 7 Denis Roy CLA 2010-04-28 10:34:16 EDT
Kim, does the current log format/method work for you?  I haven't added it to our nightly logrotate script yet, so you'll see more than 24h worth of activity.
Comment 8 Kim Moir CLA 2010-04-28 10:51:09 EDT
Yes it looks good to me. Thanks!
Comment 9 Denis Roy CLA 2010-05-10 10:14:52 EDT
Closing as fixed.
Comment 10 Christian Campo CLA 2010-06-01 12:04:32 EDT
as a side-note.....maybe it would be a good idea to fix the signing script since it still suggest to tail - f /tmp/jarsigner when "sign xxx mail ./out" is started.

Now that obviously that location has changed to tail -f /tmp/signing/signer.log.