Inconsistent datetime format in some responses

metaclassing · May 9, 2018, 1:19am

Hi,

I have been seeing some inconsistent timestamp formats from various authorizations coming back the past few weeks, some include time down to the nanosecond which breaks PHP’s Datetime parser (I need to sometimes strip off 3 numbers at the end to get an acceptable format) but other times the timestamp conforms with the IETF draft examples.

This is what I am seeing pulled from a log file:

"expires": "2018-05-11T13:31:40.60220111Z",
"expires": "2018-06-03T13:31:57Z",
"expires": "2018-06-03T13:31:57Z",
"expires": "2018-05-11T14:22:59.045308603Z",
"expires": "2018-06-03T14:23:23Z",
"expires": "2018-06-03T14:23:23Z",
"expires": "2018-05-12T13:30:02.882933025Z",
"expires": "2018-05-12T13:30:03.670421212Z",
"expires": "2018-06-04T13:30:22Z",
"expires": "2018-06-04T13:30:22Z",
"expires": "2018-06-04T13:30:24Z",
"expires": "2018-06-04T13:30:24Z",
"expires": "2018-05-12T13:30:28.677736142Z",
"expires": "2018-06-04T13:30:49Z",
"expires": "2018-06-04T13:30:49Z",
"expires": "2018-05-12T13:30:53.230914188Z",
"expires": "2018-05-12T13:30:53.989105534Z",
"expires": "2018-05-12T13:30:54.76093966Z",
"expires": "2018-06-04T13:31:24Z",
"expires": "2018-06-04T13:31:24Z",
"expires": "2018-06-04T13:31:26Z",
"expires": "2018-06-04T13:31:26Z",
"expires": "2018-06-04T13:31:29Z",
"expires": "2018-06-04T13:31:29Z",
"expires": "2018-05-12T13:31:34.730619484Z",
"expires": "2018-06-04T13:31:48Z",
"expires": "2018-06-04T13:31:48Z",
"expires": "2018-05-13T13:30:03.096100314Z",
"expires": "2018-06-05T13:30:24Z",
"expires": "2018-06-05T13:30:24Z",
"expires": "2018-05-13T13:30:27.290400382Z",
"expires": "2018-05-13T13:30:28.055870057Z",
"expires": "2018-06-05T13:30:54Z",
"expires": "2018-06-05T13:30:54Z",
"expires": "2018-06-05T13:30:56Z",
"expires": "2018-06-05T13:30:56Z",
"expires": "2018-05-13T13:31:01.095558447Z",
"expires": "2018-06-05T13:31:23Z",
"expires": "2018-06-05T13:31:23Z",
"expires": "2018-05-13T13:31:28.635812218Z",
"expires": "2018-05-13T13:31:29.388911239Z",
"expires": "2018-05-13T13:31:30.173078157Z",
"expires": "2018-06-05T13:32:03Z",
"expires": "2018-06-05T13:32:03Z",
"expires": "2018-06-05T13:32:05Z",
"expires": "2018-06-05T13:32:05Z",
"expires": "2018-06-05T13:32:07Z",
"expires": "2018-06-05T13:32:07Z",
"expires": "2018-05-13T13:32:13.190390367Z",
"expires": "2018-05-13T13:32:13.950394162Z",
"expires": "2018-05-13T13:32:14.704933615Z",
"expires": "2018-06-05T13:32:47Z",
"expires": "2018-06-05T13:32:47Z",
"expires": "2018-06-05T13:32:49Z",
"expires": "2018-06-05T13:32:49Z",
"expires": "2018-06-05T13:32:51Z",
"expires": "2018-06-05T13:32:51Z",
"expires": "2018-05-13T13:32:58.046509237Z",
"expires": "2018-05-13T13:32:58.832668002Z",
"expires": "2018-06-05T13:33:12Z",
"expires": "2018-06-05T13:33:12Z",
"expires": "2018-06-05T13:33:14Z",
"expires": "2018-06-05T13:33:14Z",
"expires": "2018-05-15T13:30:04.825143632Z",
"expires": "2018-06-07T13:30:26Z",
"expires": "2018-06-07T13:30:26Z",
"expires": "2018-05-15T13:30:29.281197396Z",
"expires": "2018-06-07T13:30:42Z",
"expires": "2018-06-07T13:30:42Z",
"expires": "2018-05-15T13:30:46.49205189Z",
"expires": "2018-06-07T13:31:12Z",
"expires": "2018-06-07T13:31:12Z",

The example authorization from https://ietf-wg-acme.github.io/acme/draft-ietf-acme-acme.html indicates that the standard datetime output should be:

"expires": "2015-03-01T14:09:00Z",

Is this something that can be made uniform and predictable? I am saving all authorizations in a database for tracking purposes and don’t gain much value in having the sub-second precision on these records. Doing string manipulation to determine if the datetime needs to be fixed up before inserting is not an ideal approach.

schoen · May 9, 2018, 5:36am

Hi @metaclassing,

According to the draft that you linked to, the format for this field is defined by RFC 3339. RFC 3339 allows fractional seconds with an unlimited number of decimal places after the decimal point:

https://tools.ietf.org/html/rfc3339#section-5.6

time-secfrac = "." 1*DIGIT

which according to the ABNF specification means that the seconds fraction may include 1 or more digits, with no largest number of digits. See also

On the other hand,

https://tools.ietf.org/html/rfc3339#section-5.3

does state that fraction seconds are expected to “rarely used” in Internet applications other than those that require precision timing.

Many computer time libraries do handle the fractional seconds correctly with no modification.

$ date -d "2018-05-12T13:31:34.730619484Z" +%s
1526131894
$ python -c 'from dateutil import parser; print(parser.parse("2018-05-12T13:31:34.730619484Z"))'
2018-05-12 13:31:34.730619+00:00

We can ask @jsha or @cpu if this could be made more consistent, but I don’t think that it violates the applicable standards at all.

metaclassing · May 9, 2018, 10:57am

I did a little coffee-time reading and think I have a potential explanation as to the inconsistency.

In Boulder the authz.expires is calculated the first time as UnixNano();

github.com

letsencrypt/boulder/blob/master/ra/ra.go#L1898


		return nil, err
	}


	return storedOrder, nil
}


// createPendingAuthz checks that a name is allowed for issuance and creates the
// necessary challenges for it and puts this and all of the relevant information
// into a corepb.Authorization for transmission to the SA to be stored
func (ra *RegistrationAuthorityImpl) createPendingAuthz(ctx context.Context, reg int64, identifier core.AcmeIdentifier) (*corepb.Authorization, error) {
	expires := ra.clk.Now().Add(ra.pendingAuthorizationLifetime).UnixNano()
	status := string(core.StatusPending)
	authz := &corepb.Authorization{
		Identifier:     &identifier.Value,
		RegistrationID: &reg,
		Status:         &status,
		Expires:        &expires,
	}


	if identifier.Type == core.IdentifierDNS && !features.Enabled(features.VAChecksGSB) {
		isSafeResp, err := ra.VA.IsSafeDomain(ctx, &vaPB.IsSafeDomainRequest{Domain: &identifier.Value})

However the database authz are stored in does not have a datatype that seems to support that fractional nanosecond precision.

github.com

letsencrypt/boulder/blob/f21a7e5ad2078563a7084f7cf0ebe80c9c0bc92b/sa/_db/migrations/20150818171317_InitialSchema.sql#L21


`LockCol` bigint(20) DEFAULT NULL,
PRIMARY KEY (`id`),
UNIQUE KEY `jwk_sha256` (`jwk_sha256`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;


CREATE TABLE `authz` (
`id` varchar(255) NOT NULL,
`identifier` varchar(255) DEFAULT NULL,
`registrationID` bigint(20) DEFAULT NULL,
`status` varchar(255) DEFAULT NULL,
`expires` datetime DEFAULT NULL,
`combinations` varchar(255) DEFAULT NULL,
`sequence` bigint(20) DEFAULT NULL,
PRIMARY KEY (`id`),
KEY `regId_idx` (`registrationID`) COMMENT 'Common lookup',
CONSTRAINT `regId_authz` FOREIGN KEY (`registrationID`) REFERENCES `registrations` (`id`) ON DELETE NO ACTION ON UPDATE NO ACTION
) ENGINE=InnoDB DEFAULT CHARSET=utf8;


CREATE TABLE `certificates` (
`registrationID` bigint(20) DEFAULT NULL,
`status` varchar(255) DEFAULT NULL,

My theory is that the precision is lost after initially calculating the authz expiration and subsequent ACME requests are provided the shorter less-precise time from the database.

Again, I am not dictating the behavior, just pointing out that this is inconsistent and depending on language and platform behavior that extra time information is either truncated, rounded, or causes an error.

jsha · May 9, 2018, 5:39pm

Thanks for the detailed analysis, @metaclassing! I think you are correct, and I think it’s reasonable to make it consistent in Boulder. I’d welcome a patch!

metaclassing · May 11, 2018, 1:01am

I took a quick stab at something, but am not the most familiar with the codebase. Hopefully TravisCI catches anything problematic with this approach.

Thanks for the time and consideration

system · June 10, 2018, 1:01am

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.