ber2der

[atooni]

Hello,

first of all thank you very much for providing the SCEP client and server. We are trying to use the SCEP server within our project as a test server to test our client against.

Our client is built in Scala on top of jscep, version 2.5.0. It seems that we are running into an issue that is similar to #20 if not the same. We have just begun to analyse the issue ourselves.

The initial code to drive our enrollment is here together with a very simple main line.

The log output from the client is here and the corresponding server output is here.

First we have tried the docker image providing scep version 1.0, then we have built our own docker image based on the current master, but got the same error message.

Any hint to investigate the issue further would be highly appreciated.

[atooni]

To help analysing the problem I have created a tcpdump:

tcpdump.txt, test.hex.gz

Also, I have tried to understand the offending message

[atooni]

A small update - we have changed out configuration a bit and were able to test against the SCEP server that we have to target later in the product. In that configuration the certificate enroll works fine with the JSCEP library.

[bjvetter]

I also see this problem when using a jscep client and trying to access the micromdm scep server (v 1.0). I can try to produce a log of the http request as received by the scep server - do you have any way of forcing that dump from the scep server itself (enable some logging) or must I capture the raw packets from the network?

[groob]

you can edit the code and add a httputil.DumpRequest(true, r) and then write that byte array to disk.

[bjvetter]

Not a Go programmer, so ... Would I put this call in the server/transport.go:decodeSCEPRequest function? I also presume I should write its return value to a file (or just pop it onto stdout).

Always wanted to learn go - just never had the free time. :-)

[bjvetter]

http.log Here's the output from httputil.DumpRequest. Hopefully it will shed light on (a) where things go wrong in micromdm/scep or (b) where jscep is producing something wrong.

[bjvetter]

Oh and one more thing - when I build from the master source instead of using the 1.0 build via zip, I get a different error. Instead of Invalid BER format, I now see: level=info ts=2019-04-10T22:49:55.108018Z caller=service_logging.go:46 component=scep_service method=PKIOperation err="ber2der: BER tag length is more than available data" took=438.699µs

Perhaps that is a better hint.

[groob]

I'll look into the log, thank you.

When you are building from source, how are you downloading the dependencies? Make sure you're using go mod download. The make deps command will enforce that.

[groob]

hmm @bjvetter, I took the request from your http.log and passed it to pkcs7.Parse, which is where the ber2der error would come from, and It parses just fine for me.

package main

import (
	"io/ioutil"

	"github.com/davecgh/go-spew/spew"
	"github.com/fullsailor/pkcs7"
)

func main() {
	data, _ := ioutil.ReadFile("79.der")
	p7, err := pkcs7.Parse(data)
	if err != nil {
		panic(err)
	}
	spew.Dump(p7)
}

go run main.go

Maybe this is not a PKCSReq that is failing but another operation? If you have client side logs that would be useful.

[groob]

Note that the master branch of https://github.com/groob/pkcs7 is over 3 years old. If you're using this project make sure you're validating the versions of transitive dependencies correctly (TL;DR use make deps) I can reproduce some of the reported issues with outdated dependencies, but it all appears to work with the correct pinned versions.

[bjvetter]

I followed the README.md instructions: go get github.com/micromdm/scep make deps make build

I'll be out the next day, but will take a closer look at versions as well as run the pkcs7.Parse() program/test you posted to see if that works in my environment outside of the scep server. I can try to see if I can enable some client logging, but not sure how easy that will be.

[bjvetter]

After some experimenting with your main.go program, it parses the data in the http request correctly. I then switched it to use github.com/groob/pkcs7 instead and I get a "Invalid BER format" error, so there is definitely something different about the two different pkcs7 repos w.r.t. how they operate.

Not being experienced with go, I ran "make deps", etc, and tried to replace the older groob/pkcs7 with the newer fullsailor/pkcs7 package, but apparently, there have been changes such that it no longer compiles. I see the following errors: ../../scep/scep.go:318:17: p7.EncryptionAlgorithm undefined (type *pkcs7.PKCS7 has no field or method EncryptionAlgorithm) ../../scep/scep.go:449:26: too many arguments in call to pkcs7.Encrypt ../../scep/scep.go:449:53: undefined: pkcs7.WithEncryptionAlgorithm ../../scep/scep.go:542:26: too many arguments in call to pkcs7.Encrypt ../../scep/scep.go:542:54: undefined: pkcs7.WithEncryptionAlgorithm

I don't see evidence of functions/fields/arguments with these names. I do see the following in the latest fullsailor and groob repos:

// TODO(fullsailor): Add support for encrypting content with other algorithms
func Encrypt(content []byte, recipients []*x509.Certificate) ([]byte, error) {

Digging around in the go pkg repo after the make deps, I see the version of scep.go that has a different signature that looks like it supports a collection of options. It was in this repo: go/pkg/mod/github.com/groob/pkcs7\@v0.0.0-20180824154052-36585635cb64

So make deps is pulling down a pkcs7 library that is at least compatible.

So not sure how one validates "the versions of transitive dependencies correctly" in go, but following the build seems to produce something that will compile. Substituting for the master builds of pkcs7 from fullsailor or groob won't.

BUT, I think this is all moot and not the core issue.

I hacked the transport code to parse the http message received using the pcs7 and spew it out like you have in your main.go example. It parses the message just fine and spews it all over stdout. Then when it calls the SCEPRequest() function with the same message as input, I get the "BER tag length is more than available data" error.

So I don't think the issue is in the pkcs7 handling, but in the the SCEPRequest handler somewhere.

[groob]

If you dump the request out after reading it for debugging you cannot pass it along to be read a second time. Reading it zeroes it out. You would have to reconstruct the body again from your byte slice. So your new error messsge might be a red herring.

To test this properly delete all your local changes and reinstall the project, but compile the dependencies correctly this time. If it still fails please attach any logs.

[groob]

As I already mentioned the head of this project depends on a branch in the groob/pkcs7 repo. The master version of that branch is 3 years old.

Using the makefile should result in the correct branch. Using got clone or go get manually to fetch dependencies will fail.

[bjvetter]

Just to be clear, I did not use git manually. I did perform the installing/compiling instructions from the readme on your github root dir:

# go get github.com/micromdm/scep
# make deps
# make build

I only attempted to use git directly when I read your response about the old pkcs7 library and statement about "transitive dependencies" thinking I needed to get an updated version. I have blown away all of those "variations" and was adding debug logic to the code that is built as discussed above (got get...; make deps; make build).

To recap what I am seeing:

1. If I use the assets for your 1.0 release under the Github "Releases" link, I get an error "ber2der: Invalid BER format".
2. If I build using your install/compile instructions, I get an error: "ber2der: BER tag length is more than available data". This appears to be a different error than in the first case unless there was a rewording of the error message.

When I add code to parse the request (after the message is retrieved but before calling SCEPRequest with the message), the call to pkcs7.Parse(msg) is successful and it happily "spews" out a dump of the request. It still gets the exact same error "ber2der: BER tag length is more than available data". The code in decodeSCEPRequest() is the following:

func decodeSCEPRequest(ctx context.Context, r *http.Request) (interface{}, error) {
    msg, err := message(r)
    if err != nil {
        return nil, err
    }
    defer r.Body.Close()

    // debug code only looks at the scep request with the CRL.
    if len(msg) == 2770 {
        p7, err := pkcs7.Parse(msg)
        if err != nil {
            panic(err)
        }
        spew.Dump(p7)
    }

    request := SCEPRequest{
        Message:   msg,
        Operation: r.URL.Query().Get("operation"),
    }

    return request, nil
}

I now have another SCEP server to test against (a jscep-based server) and it handles the request without an error. I am happy to help you debug through this issue if you wish, or I can just go away.

[groob]

your call to Parse is under a conditional. What if you remove the conditional, is it still always happy?

[bjvetter]

If I remove the conditional/debug code, it still fails with the same error. The length being 2770 is the actual SCEPRequest that I care about (the actual CSR). I was using the 2770 length to avoid looking at the getCACaps and other ops that were being issued.

If I force it to return "nil" instead of dropping out after the conditional and create/return the SCEPRequest(), I get a whole lot of unhappiness but I do not see the error "ber2der: BER tag length is more than available data". I also wrote out some messages before and after the SCEPRequest call. SCEPRequest seems to not be the source of the error message either.

The error happens after we return the request object that was parsed by SCEPRequest. All my debugging/logging so far seems to suggest that the message passed to SCEPRequest is a good CSR - it is parsed properly by the pkcs7 package without an error and its resulting object is "spewable". Now perhaps what is being "spewed" isn't fully happy by whoever is receiving the actual request object.

I can capture the "spewed output" and provide that to you if you wish, unless something else to try would be better.

spew.txt

[bjvetter]

On impulse, I went into the dependent pkcs7 library (in ber.go) and added a "panic(...)" call when that error is generated. I see the following stack trace if that is at all helpful:

2019/04/15 19:51:04 http: panic serving 10.40.4.63:60444: BER tag length is more than available data
goroutine 7 [running]:
net/http.(*conn).serve.func1(0xc0000c8c80)
	/usr/local/go/src/net/http/server.go:1769 +0x139
panic(0x13140a0, 0x13fc070)
	/usr/local/go/src/runtime/panic.go:522 +0x1b5
github.com/fullsailor/pkcs7.readObject(0xc0002ec400, 0x3e8, 0x3e8, 0x298, 0x20, 0x20, 0x13349a0, 0x109916b, 0xc0002ec77a)
	/Users/bjv/go/pkg/mod/github.com/groob/[email protected]/ber.go:191 +0x851
github.com/fullsailor/pkcs7.readObject(0xc0002ec400, 0x3e8, 0x3e8, 0x296, 0x0, 0x0, 0x0, 0x2, 0x0)
	/Users/bjv/go/pkg/mod/github.com/groob/[email protected]/ber.go:212 +0x30f
github.com/fullsailor/pkcs7.readObject(0xc0002ec400, 0x3e8, 0x3e8, 0x26a, 0x0, 0x0, 0x0, 0x2, 0x0)
	/Users/bjv/go/pkg/mod/github.com/groob/[email protected]/ber.go:212 +0x30f
github.com/fullsailor/pkcs7.readObject(0xc0002ec400, 0x3e8, 0x3e8, 0xf, 0x10, 0x10, 0x13349a0, 0x109916b, 0xc0002ec77a)
	/Users/bjv/go/pkg/mod/github.com/groob/[email protected]/ber.go:212 +0x30f
github.com/fullsailor/pkcs7.readObject(0xc0002ec400, 0x3e8, 0x3e8, 0xd, 0x0, 0x0, 0x0, 0x1, 0x0)
	/Users/bjv/go/pkg/mod/github.com/groob/[email protected]/ber.go:212 +0x30f
github.com/fullsailor/pkcs7.readObject(0xc0002ec400, 0x3e8, 0x3e8, 0x0, 0xc0002e0ff0, 0x100db28, 0x60, 0x1348660, 0x1)
	/Users/bjv/go/pkg/mod/github.com/groob/[email protected]/ber.go:212 +0x30f
github.com/fullsailor/pkcs7.ber2der(0xc0002ec400, 0x3e8, 0x3e8, 0x1305000, 0xc00032d220, 0x0, 0x0, 0x2)
	/Users/bjv/go/pkg/mod/github.com/groob/[email protected]/ber.go:64 +0xe4
github.com/fullsailor/pkcs7.Parse(0xc0002ec400, 0x3e8, 0x3e8, 0x0, 0x0, 0x6)
	/Users/bjv/go/pkg/mod/github.com/groob/[email protected]/pkcs7.go:130 +0xe5
github.com/micromdm/scep/scep.(*PKIMessage).DecryptPKIEnvelope(0xc00016c240, 0xc000100b00, 0xc0000ac0c0, 0x0, 0x0)
	/Users/bjv/go/src/github.com/micromdm/scep/scep/scep.go:309 +0x64
github.com/micromdm/scep/server.(*service).PKIOperation(0xc000134000, 0x140a4a0, 0xc00028c7e0, 0xc0002c4000, 0xad2, 0xe00, 0x1647740, 0x30, 0x1a, 0x0, ...)
	/Users/bjv/go/src/github.com/micromdm/scep/server/service.go:90 +0x112
github.com/micromdm/scep/server.(*loggingService).PKIOperation(0xc000132220, 0x140a4a0, 0xc00028c7e0, 0xc0002c4000, 0xad2, 0xe00, 0x0, 0x0, 0x0, 0x0, ...)
	/Users/bjv/go/src/github.com/micromdm/scep/server/service_logging.go:52 +0xeb
github.com/micromdm/scep/server.MakeSCEPEndpoint.func1(0x140a4a0, 0xc00028c7e0, 0x1352b40, 0xc000097b30, 0xc00032c4c0, 0x2, 0x2, 0xc0002e19f0)
	/Users/bjv/go/src/github.com/micromdm/scep/server/endpoint.go:145 +0x252
github.com/micromdm/scep/server.EndpointLoggingMiddleware.func1.1(0x140a4a0, 0xc00028c7e0, 0x1352b40, 0xc000097b30, 0x0, 0x0, 0x0, 0x0)
	/Users/bjv/go/src/github.com/micromdm/scep/server/endpoint.go:188 +0x175
github.com/go-kit/kit/transport/http.Server.ServeHTTP(0xc0001322c0, 0x13a8b38, 0x13a8b40, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x13a8ac0, ...)
	/Users/bjv/go/pkg/mod/github.com/go-kit/[email protected]/transport/http/server.go:108 +0x311
github.com/gorilla/mux.(*Router).ServeHTTP(0xc00014e0f0, 0x1409c60, 0xc00014c2a0, 0xc000208800)
	/Users/bjv/go/pkg/mod/github.com/gorilla/[email protected]/mux.go:114 +0xdb
net/http.serverHandler.ServeHTTP(0xc0000b8ea0, 0x1409c60, 0xc00014c2a0, 0xc0002a6000)
	/usr/local/go/src/net/http/server.go:2774 +0xa8
net/http.(*conn).serve(0xc0000c8c80, 0x140a3e0, 0xc0000ae040)
	/usr/local/go/src/net/http/server.go:1878 +0x851
created by net/http.(*Server).Serve
	/usr/local/go/src/net/http/server.go:2884 +0x2f4

[groob]

Ah I see. Parse is called twice, and we're not looking at DecryptPKIEnvelope, which is where the message is failing.

Any chance you could store the []byte which is being passed to pkcs7.Parse in the Decrypt call? https://github.com/micromdm/scep/blob/1e0c4b782f3f2e1e6f81da5f82444a6cedc89df3/scep/scep.go#L309

[bjvetter]

Interestingly enough, the data being written is only 1000 bytes long (perhaps that is what you expected?) reqdata.zip

The zip file contains both the original binary data received in the http request and the data that is presented to pkcs7.parse in the scep/scep/scep.go (DecryptPKIEnvelope)

[groob]

fwiw asn1parse fails too

cat decryptpkienvelope.dat |openssl asn1parse -inform DER

Error in encoding
4626351724:error:0DFFF09B:asn1 encoding routines:CRYPTO_internal:too long:/BuildRoot/Library/Caches/com.apple.xbs/Sources/libressl/libressl-22.250.1/libressl-2.6/crypto/asn1/asn1_lib.c:143:

[groob]

And yes, i can reproduce with Go.

Now the question is, does the go pkcs7 library fail to cut off the data as needed, or is the client encoding it wrong.

[groob]

making some progress with the payload. Somehow the full size gets converted to 1000 during a asn1.Unmarshal call.

[bjvetter]

So just to be clear, the raw pkcs7 data that is captured in transport.go is 2770 bytes and is happily parsed by openssl - either by openssl pkcs7 or openssl asn1parse. But whatever that 1000 bytes of data is, it doesn't seem parseable by either. I looked at the two files a tad closer, and while they start out looking the same, they diverge around byte #18. So, it is pretty messed up.

BTW, the payload seems to work fine with another SCEP server, so either the client/server are using some non-standard encode/decode scheme (seems unlikely), there is something extra or missing in the CSR that their server is handling and this one is not, or there is just a decoding bug here.

[groob]

I tested this patch here, and it appears to work (just the part inside the if compound.IsCompound conditional ) https://github.com/innoq/pkcs7/commit/aa5eda5d2b3d6874f6594067f55e2750015d8f16

I would have to incorporate it into my fork before you could use it

[bjvetter]

I was able to hack it into my go packages. It does work now. I was returned a happy certificate that I was able to import into my keystore. Thanks for all of the help figuring this out. It is a very nice little package and will save me a lot of time setting up/tearing down my test harness - it is much simpler than some of the alternatives.

[groob]

Neat. I'm glad that worked out. I'll hopefully find the time to get this fixed properly and merged into upstream.

[bjvetter]

And thanks for putting up with my Go-noobiness. :-)

[jessepeterson]

Looks like @oeufdure submitted a PR that may include this fix in our fork of mozilla's scep here: https://github.com/omorsi/pkcs7/pull/2

[bjvetter]

I tried using the latest version recently updated from the binary that was released. When I send a release from a an application that uses the jscep library (from an Android device), I get the same ber2der error that I saw a while back ago with the previous.

@jessepeterson, Based upon your previous comment is this something that was expected to be fixed in the release, or maybe it was fixed in the source, or is it still outstanding?

The log output from the server command is:

./scepserver-darwin-amd64 -depot depot -port 2016 -challenge=secret level=info ts=2021-07-22T16:37:52.203909Z caller=scepserver.go:163 transport=http address=:2016 msg=listening level=info ts=2021-07-22T16:47:32.598428Z caller=service_logging.go:22 component=scep_service method=GetCACaps err=null took=644ns level=info ts=2021-07-22T16:47:32.598504Z caller=endpoint.go:186 op=GetCACaps error=null took=118.197µs level=info ts=2021-07-22T16:47:32.598538Z caller=logutil.go:70 component=http method=GET status=200 proto=HTTP/1.1 host=10.40.4.202 user_agent="Dalvik/2.1.0 (Linux; U; Android 11; Pixel 5 Build/RQ3A.210605.005)" path="/scep?operation=GetCACaps&message=NDESCA" level=info ts=2021-07-22T16:47:32.60727Z caller=service_logging.go:34 component=scep_service method=GetCACert message=NDESCA err=null took=1.095µs level=info ts=2021-07-22T16:47:32.607326Z caller=endpoint.go:186 op=GetCACert error=null took=57.214µs level=info ts=2021-07-22T16:47:32.607365Z caller=logutil.go:70 component=http method=GET status=200 proto=HTTP/1.1 host=10.40.4.202 user_agent="Dalvik/2.1.0 (Linux; U; Android 11; Pixel 5 Build/RQ3A.210605.005)" path="/scep?operation=GetCACert&message=NDESCA" level=info ts=2021-07-22T16:47:32.645774Z caller=service_logging.go:47 component=scep_service method=PKIOperation err="ber2der: Invalid BER format" took=15.687µs level=info ts=2021-07-22T16:47:32.645824Z caller=endpoint.go:186 op=PKIOperation error=null took=61.233µs level=info ts=2021-07-22T16:47:32.64585Z caller=logutil.go:70 component=http method=POST status=500 proto=HTTP/1.1 host=10.40.4.202 user_agent="Dalvik/2.1.0 (Linux; U; Android 11; Pixel 5 Build/RQ3A.210605.005)" path="/scep?operation=PKIOperation"