start-build is failing with 400 bad request error

[gandhi542]

@rromannissen
Hi rromannissen,

My aim is to deploy NiFi flows on OCP which is running on aws. As part of it found your repo
( https://github.com/rromannissen/nifi-openshift ) and trying to replicate the things you mentioned in it.
I have cloned the repo to my local and created the buildconfig as you mentioned. When trying to start the build using the command " oc start-build nifi-ocp --from-file=./base " getting an error as "Error from server (BadRequest): unable to wait for build to run: timed out waiting for the condition " with response as below
server response object: [{
"metadata": {},
"status": "Failure",
"message": "unable to wait for build nifi-ocp-8 to run: timed out waiting for the condition",
"reason": "BadRequest",
"code": 400
}]

Unable to find the cause of this issue and please help on this
Openshift version : 4.8.12

Below is the full log

I1130 12:04:20.889478 25104 loader.go:379] Config loaded from file: C:\Users\948690/.kube/config
I1130 12:04:20.900477 25104 repository.go:450] Executing git show -s HEAD --format=%H%n%an%n%ae%n%cn%n%ce%n%B
Uploading directory "base" as binary input for the build ...
I1130 12:04:21.002483 25104 tar.go:238] Adding "C:\Mine\nifi\OCP_Template\nifi-openshift\base" to tar ...
I1130 12:04:21.002483 25104 round_trippers.go:425] curl -k -v -XPOST -H "Accept: application/json, /" -H "User-Agent: oc.exe/4.7.0 (windows/amd64) kubernetes/95881af" -H "Authorization: Bearer " 'https://api.openson-cluster.openson-openshift.com:6443/apis/build.openshift.io/v1/namespaces/ocp-temp/buildconfigs/nifi-ocp/instantiatebinary?name=nifi-ocp&namespace=ocp-temp&revision.authorEmail=rromannissen%40gmail.com&revision.authorName=Ram%C3%B3n+Rom%C3%A1n+Nissen&revision.commit=93268581f0d76f8255bb5d32a74deadd9b941037&revision.committerEmail=rromannissen%40gmail.com&revision.committerName=Ram%C3%B3n+Rom%C3%A1n+Nissen&revision.message=Fixed+typo'
I1130 12:04:21.014481 25104 tar.go:336] Adding to tar: C:\Mine\nifi\OCP_Template\nifi-openshift\base\Dockerfile as Dockerfile
I1130 12:04:21.238479 25104 tar.go:336] Adding to tar: C:\Mine\nifi\OCP_Template\nifi-openshift\base\bootstrap.conf as bootstrap.conf
I1130 12:04:21.246482 25104 tar.go:336] Adding to tar: C:\Mine\nifi\OCP_Template\nifi-openshift\base\sh as sh
I1130 12:04:21.251483 25104 tar.go:336] Adding to tar: C:\Mine\nifi\OCP_Template\nifi-openshift\base\sh\common.sh as sh/common.sh
I1130 12:04:21.255476 25104 tar.go:336] Adding to tar: C:\Mine\nifi\OCP_Template\nifi-openshift\base\sh\secure.sh as sh/secure.sh
I1130 12:04:21.260477 25104 tar.go:336] Adding to tar: C:\Mine\nifi\OCP_Template\nifi-openshift\base\sh\start.sh as sh/start.sh
I1130 12:04:21.265476 25104 tar.go:336] Adding to tar: C:\Mine\nifi\OCP_Template\nifi-openshift\base\sh\toolkit.sh as sh/toolkit.sh
I1130 12:04:21.270477 25104 tar.go:336] Adding to tar: C:\Mine\nifi\OCP_Template\nifi-openshift\base\sh\update_cluster_state_management.sh as sh/update_cluster_state_management.sh
I1130 12:04:21.275478 25104 tar.go:336] Adding to tar: C:\Mine\nifi\OCP_Template\nifi-openshift\base\sh\update_login_providers.sh as sh/update_login_providers.sh
............................................................I1130 12:09:22.354928 25104 round_trippers.go:445] POST https://api.openson-cluster.openson-openshift.com:6443/apis/build.openshift.io/v1/namespaces/ocp-temp/buildconfigs/nifi-ocp/instantiatebinary?name=nifi-ocp&namespace=ocp-temp&revision.authorEmail=rromannissen%40gmail.com&revision.authorName=Ram%C3%B3n+Rom%C3%A1n+Nissen&revision.commit=93268581f0d76f8255bb5d32a74deadd9b941037&revision.committerEmail=rromannissen%40gmail.com&revision.committerName=Ram%C3%B3n+Rom%C3%A1n+Nissen&revision.message=Fixed+typo 400 Bad Request in 301352 milliseconds
I1130 12:09:22.354928 25104 round_trippers.go:451] Response Headers:
I1130 12:09:22.354928 25104 round_trippers.go:454] Audit-Id: 90f3acc5-e947-4ba9-9238-b90fc09f2fed
I1130 12:09:22.354928 25104 round_trippers.go:454] Audit-Id: 90f3acc5-e947-4ba9-9238-b90fc09f2fed
I1130 12:09:22.354928 25104 round_trippers.go:454] Cache-Control: no-cache, private
I1130 12:09:22.354928 25104 round_trippers.go:454] Cache-Control: no-store
I1130 12:09:22.354928 25104 round_trippers.go:454] Content-Type: application/json
I1130 12:09:22.354928 25104 round_trippers.go:454] Date: Tue, 30 Nov 2021 06:39:19 GMT
I1130 12:09:22.354928 25104 round_trippers.go:454] Content-Length: 194
I1130 12:09:22.354928 25104 request.go:1107] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"unable to wait for build nifi-ocp-8 to run: timed out waiting for the condition","reason":"BadRequest","code":400}

Uploading finished
I1130 12:09:22.355945 25104 helpers.go:216] server response object: [{
"metadata": {},
"status": "Failure",
"message": "unable to wait for build nifi-ocp-8 to run: timed out waiting for the condition",
"reason": "BadRequest",
"code": 400
}]
F1130 12:09:22.355945 25104 helpers.go:115] Error from server (BadRequest): unable to wait for build nifi-ocp-8 to run: timed out waiting for the condition
goroutine 1 [running]:
k8s.io/klog/v2.stacks(0xc000006001, 0xc00001e000, 0x9e, 0x14e)
/go/src/github.com/openshift/oc/vendor/k8s.io/klog/v2/klog.go:1026 +0xbf
k8s.io/klog/v2.(*loggingT).output(0x4e94a20, 0xc000000003, 0x0, 0x0, 0xc0000ea4d0, 0x4c389e6, 0xa, 0x73, 0xbcf300)
/go/src/github.com/openshift/oc/vendor/k8s.io/klog/v2/klog.go:975 +0x19e
k8s.io/klog/v2.(*loggingT).printDepth(0x4e94a20, 0xc000000003, 0x0, 0x0, 0x0, 0x0, 0x2, 0xc0007081d0, 0x1, 0x1)
/go/src/github.com/openshift/oc/vendor/k8s.io/klog/v2/klog.go:732 +0x185
k8s.io/klog/v2.FatalDepth(...)
/go/src/github.com/openshift/oc/vendor/k8s.io/klog/v2/klog.go:1488
k8s.io/kubectl/pkg/cmd/util.fatal(0xc0013b60e0, 0x6f, 0x1)
/go/src/github.com/openshift/oc/vendor/k8s.io/kubectl/pkg/cmd/util/helpers.go:93 +0x27a
k8s.io/kubectl/pkg/cmd/util.checkErr(0x39b86e0, 0xc0011fc320, 0x37136e8)
/go/src/github.com/openshift/oc/vendor/k8s.io/kubectl/pkg/cmd/util/helpers.go:188 +0x965
k8s.io/kubectl/pkg/cmd/util.CheckErr(...)
/go/src/github.com/openshift/oc/vendor/k8s.io/kubectl/pkg/cmd/util/helpers.go:115
github.com/openshift/oc/pkg/cli/startbuild.NewCmdStartBuild.func1(0xc00132cdc0, 0xc001509e40, 0x1, 0x4)
/go/src/github.com/openshift/oc/pkg/cli/startbuild/startbuild.go:160 +0xfc
github.com/spf13/cobra.(*Command).execute(0xc00132cdc0, 0xc001509e00, 0x4, 0x4, 0xc00132cdc0, 0xc001509e00)
/go/src/github.com/openshift/oc/vendor/github.com/spf13/cobra/command.go:854 +0x2c2
github.com/spf13/cobra.(*Command).ExecuteC(0xc000b18b00, 0x6, 0xc000b18b00, 0x6)
/go/src/github.com/openshift/oc/vendor/github.com/spf13/cobra/command.go:958 +0x375
github.com/spf13/cobra.(*Command).Execute(...)
/go/src/github.com/openshift/oc/vendor/github.com/spf13/cobra/command.go:895
main.main()
/go/src/github.com/openshift/oc/cmd/oc/oc.go:93 +0x5e5

goroutine 6 [chan receive]:
k8s.io/klog/v2.(*loggingT).flushDaemon(0x4e94a20)
/go/src/github.com/openshift/oc/vendor/k8s.io/klog/v2/klog.go:1169 +0x92
created by k8s.io/klog/v2.init.0
/go/src/github.com/openshift/oc/vendor/k8s.io/klog/v2/klog.go:417 +0xe5

goroutine 16 [select, 5 minutes]:
io.(*pipe).Read(0xc0011da0c0, 0xc000b1c000, 0x1000, 0x1000, 0x3034f60, 0x1, 0xc000b1c000)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/io/pipe.go:57 +0xee
io.(*PipeReader).Read(0xc00048e038, 0xc000b1c000, 0x1000, 0x1000, 0xc000aa7e48, 0xc296c0, 0xc000082000)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/io/pipe.go:134 +0x53
bufio.(*Scanner).Scan(0xc000486200, 0xc25f01)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/bufio/scan.go:214 +0xab
github.com/openshift/oc/pkg/cli/admin/mustgather.newPrefixWriter.func1(0xc000486200, 0x39ba2e0, 0xc000006018, 0x3528c54, 0x17)
/go/src/github.com/openshift/oc/pkg/cli/admin/mustgather/mustgather.go:496 +0x149
created by github.com/openshift/oc/pkg/cli/admin/mustgather.newPrefixWriter
/go/src/github.com/openshift/oc/pkg/cli/admin/mustgather/mustgather.go:495 +0x1d0

goroutine 15 [select]:
k8s.io/apimachinery/pkg/util/wait.BackoffUntil(0x37135f8, 0x39b89e0, 0xc000409860, 0x1, 0xc000050420)
/go/src/github.com/openshift/oc/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:167 +0x149
k8s.io/apimachinery/pkg/util/wait.JitterUntil(0x37135f8, 0x12a05f200, 0x0, 0xc0011da201, 0xc000050420)
/go/src/github.com/openshift/oc/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133 +0x9f
k8s.io/apimachinery/pkg/util/wait.Until(...)
/go/src/github.com/openshift/oc/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:90
k8s.io/apimachinery/pkg/util/wait.Forever(0x37135f8, 0x12a05f200)
/go/src/github.com/openshift/oc/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:81 +0x56
created by k8s.io/component-base/logs.InitLogs
/go/src/github.com/openshift/oc/vendor/k8s.io/component-base/logs/logs.go:58 +0x92

goroutine 42 [IO wait]:
internal/poll.runtime_pollWait(0x20eba0e6ef8, 0x72, 0x39bd420)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/runtime/netpoll.go:222 +0x65
internal/poll.(*pollDesc).wait(0xc000ba55b8, 0x72, 0x4c63900, 0x0, 0x0)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/internal/poll/fd_poll_runtime.go:87 +0x4c
internal/poll.execIO(0xc000ba5418, 0x37127e0, 0xbd92b23a70915901, 0xa23778b5b60e1a1d, 0x984e71fb5be48dfc)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/internal/poll/fd_windows.go:175 +0x105
internal/poll.(*FD).Read(0xc000ba5400, 0xc0011f6000, 0x1587, 0x1587, 0x0, 0x0, 0x0)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/internal/poll/fd_windows.go:441 +0x2ff
net.(*netFD).Read(0xc000ba5400, 0xc0011f6000, 0x1587, 0x1587, 0xc001573760, 0x39647bd, 0xc0012ea4e0)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/net/fd_posix.go:55 +0x56
net.(*conn).Read(0xc000006378, 0xc0011f6000, 0x1587, 0x1587, 0x0, 0x0, 0x0)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/net/net.go:182 +0x95
crypto/tls.(*atLeastReader).Read(0xc00054a100, 0xc0011f6000, 0x1587, 0x1587, 0xdc, 0x1582, 0xc001573710)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/crypto/tls/conn.go:779 +0x67
bytes.(*Buffer).ReadFrom(0xc0012ea600, 0x39b49c0, 0xc00054a100, 0xbcc4ac, 0x315b6a0, 0x342d5c0)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/bytes/buffer.go:204 +0xbb
crypto/tls.(*Conn).readFromUntil(0xc0012ea380, 0x20eba0e6fe0, 0xc000006378, 0x5, 0xc000006378, 0xcb)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/crypto/tls/conn.go:801 +0xf3
crypto/tls.(*Conn).readRecordOrCCS(0xc0012ea380, 0x0, 0x0, 0xc001573d18)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/crypto/tls/conn.go:608 +0x12d
crypto/tls.(*Conn).readRecord(...)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/crypto/tls/conn.go:576
crypto/tls.(*Conn).Read(0xc0012ea380, 0xc0011ff000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/crypto/tls/conn.go:1252 +0x16d
bufio.(*Reader).Read(0xc000106960, 0xc0001d8818, 0x9, 0x9, 0xc001573d18, 0x3714400, 0x114a898)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/bufio/bufio.go:227 +0x238
io.ReadAtLeast(0x39b4780, 0xc000106960, 0xc0001d8818, 0x9, 0x9, 0x9, 0xc00008e060, 0x0, 0x39b4c40)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/io/io.go:314 +0x8e
io.ReadFull(...)
/opt/rh/go-toolset-1.15/root/usr/lib/go-toolset-1.15-golang/src/io/io.go:333
golang.org/x/net/http2.readFrameHeader(0xc0001d8818, 0x9, 0x9, 0x39b4780, 0xc000106960, 0x0, 0x0, 0xc001573dd0, 0xc2f6a9)
/go/src/github.com/openshift/oc/vendor/golang.org/x/net/http2/frame.go:237 +0x8e
golang.org/x/net/http2.(*Framer).ReadFrame(0xc0001d87e0, 0xc0011de180, 0x0, 0x0, 0x0)
/go/src/github.com/openshift/oc/vendor/golang.org/x/net/http2/frame.go:492 +0xa8
golang.org/x/net/http2.(*clientConnReadLoop).run(0xc001573fa8, 0x0, 0x0)
/go/src/github.com/openshift/oc/vendor/golang.org/x/net/http2/transport.go:1819 +0xe7
golang.org/x/net/http2.(*ClientConn).readLoop(0xc00150c480)
/go/src/github.com/openshift/oc/vendor/golang.org/x/net/http2/transport.go:1741 +0x76
created by golang.org/x/net/http2.(*Transport).newClientConn
/go/src/github.com/openshift/oc/vendor/golang.org/x/net/http2/transport.go:705 +0x6c5

[rromannissen]

Hi @gandhi542,

I'm sorry to say that I won't be maintaining this repo anymore. This is something that was developed as part of a consulting engagement back in the day, and shared as a PoC just in case anyone might get some benefit out of this. The target OCP version for this was 3.11, so this could be part of the problem, although I would say that it might be related to the oc client version you are using not being aligned with the one of the cluster you are connected to, or maybe some proxy in the middle doing some funky stuff.

I'll keep the issue open just in case anyone finds a solution for this.

Greetings.

[gandhi542]

Hi @gandhi542,

I'm sorry to say that I won't be maintaining this repo anymore. This is something that was developed as part of a consulting engagement back in the day, and shared as a PoC just in case anyone might get some benefit out of this. The target OCP version for this was 3.11, so this could be part of the problem, although I would say that it might be related to the oc client version you are using not being aligned with the one of the cluster you are connected to, or maybe some proxy in the middle doing some funky stuff.

I'll keep the issue open just in case anyone finds a solution for this.

Greetings.

Hi @rromannissen

Thanks for your reply. I was using OCP 4.8.12 and this bad request error is resolved and it got some progress. When deploying the flow as an application the pod is running and giving the below logs and going into crashloopbackerror, unable to find a resolution for this issue. It would be very helpful if you share any resolution.

Logs (Added some echo statements in the shell scripts to debug)
starting start.sh
In start.sh@line21
starting common.sh
NIFI_HOME /opt/nifi/nifi-current
End of common.sh
In start.sh@line25
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
In start.sh@line36
starting toolkit.sh
nifi_props_file /opt/nifi/nifi-current/conf/nifi.properties
nifi_toolkit_props_file /opt/nifi/nifi-current/.nifi-cli.nifi.properties
nifi_bootstrap_file /opt/nifi/nifi-current/conf/bootstrap.conf
root
/opt/nifi/nifi-current
end of toolkit.sh
replacing target file /opt/nifi/nifi-current/.nifi-cli.nifi.properties
In start.sh@line39
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/nifi.properties
replacing target file /opt/nifi/nifi-current/conf/bootstrap.conf
replacing target file /opt/nifi/nifi-current/conf/bootstrap.conf
replacing target file /opt/nifi/nifi-current/conf/bootstrap.conf
starting update_cluster_state_management.sh
End of update_cluster_state_management.sh
Auth :
NIFI_WEB_PROXY_HOST :
before tail...
After tail...
before trap...
after trap...
Before echo NiFi PID statement...
NiFi running with PID 33.
After echo NiFi PID statement...
Before wait statement at the end
tail: cannot open '/opt/nifi/nifi-current/logs/nifi-app.log' for reading: No such file or directory

Java home: /usr/local/openjdk-8
NiFi home: /opt/nifi/nifi-current

Bootstrap Config File: /opt/nifi/nifi-current/conf/bootstrap.conf

2021-12-21 08:22:48,524 INFO [main] org.apache.nifi.bootstrap.Command Starting Apache NiFi...
2021-12-21 08:22:48,524 INFO [main] org.apache.nifi.bootstrap.Command Working Directory: /opt/nifi/nifi-current
2021-12-21 08:22:48,524 INFO [main] org.apache.nifi.bootstrap.Command Command: /usr/local/openjdk-8/bin/java -classpath /opt/nifi/nifi-current/./conf:/opt/nifi/nifi-current/./lib/javax.servlet-api-3.1.0.jar:/opt/nifi/nifi-current/./lib/jcl-over-slf4j-1.7.30.jar:/opt/nifi/nifi-current/./lib/jetty-schemas-3.1.jar:/opt/nifi/nifi-current/./lib/jul-to-slf4j-1.7.30.jar:/opt/nifi/nifi-current/./lib/log4j-over-slf4j-1.7.30.jar:/opt/nifi/nifi-current/./lib/logback-classic-1.2.3.jar:/opt/nifi/nifi-current/./lib/logback-core-1.2.3.jar:/opt/nifi/nifi-current/./lib/nifi-api-1.13.2.jar:/opt/nifi/nifi-current/./lib/nifi-framework-api-1.13.2.jar:/opt/nifi/nifi-current/./lib/nifi-nar-utils-1.13.2.jar:/opt/nifi/nifi-current/./lib/nifi-properties-1.13.2.jar:/opt/nifi/nifi-current/./lib/nifi-runtime-1.13.2.jar:/opt/nifi/nifi-current/./lib/nifi-server-api-1.13.2.jar:/opt/nifi/nifi-current/./lib/nifi-stateless-api-1.13.2.jar:/opt/nifi/nifi-current/./lib/nifi-stateless-bootstrap-1.13.2.jar:/opt/nifi/nifi-current/./lib/slf4j-api-1.7.30.jar -Dorg.apache.jasper.compiler.disablejsr199=true -Djavax.security.auth.useSubjectCredsOnly=true -Djava.security.egd=file:/dev/urandom -Dsun.net.http.allowRestrictedHeaders=true -Djava.net.preferIPv4Stack=true -Djava.awt.headless=true -XX:+UseG1GC -Djava.protocol.handler.pkgs=sun.net.www.protocol -Dnifi.properties.file.path=/opt/nifi/nifi-current/./conf/nifi.properties -Dnifi.bootstrap.listen.port=40955 -Dapp=NiFi -Dorg.apache.nifi.bootstrap.config.log.dir=/opt/nifi/nifi-current/logs org.apache.nifi.NiFi
2021-12-21 08:22:48,566 INFO [main] org.apache.nifi.bootstrap.Command Launched Apache NiFi with Process ID 55
tail: '/opt/nifi/nifi-current/logs/nifi-app.log' has appeared; following new file
After wait statement at the end

Thanks,
Gandhi