Skip to content

Instantly share code, notes, and snippets.

View edtan's full-sized avatar

Ed edtan

4 followers · 1 following
View GitHub Profile
@edtan
edtan / web.log
Created September 13, 2019 21:17
Concourse issue #4162 debugging - improved database query logs including queries in transactions
Get Step
# Start of get step initialization phase
{"timestamp":"2019-09-13T20:12:34.819843499Z","level":"info","source":"atc","message":"atc.build-tracker.track.get-step.initializing","data":{"build":2,"job":"test","job-id":1,"pipeline":"simple","session":"18.12.3","step-name":"git-repo"}}
{"timestamp":"2019-09-13T20:12:34.821090354Z","level":"debug","source":"atc","message":"atc.log-conn.atc.log-conn.buildEventSource-collectEvents","data":{"duration":"589.587µs","query":"SELECT builds.completed FROM builds WHERE builds.id = $1","session":"4"}}
{"timestamp":"2019-09-13T20:12:34.821319537Z","level":"debug","source":"atc","message":"atc.db.log-tx.BaseResourceType-Find","data":{"duration":"553.514µs","query":"SELECT id, unique_version_history FROM base_resource_types WHERE name = $1 FOR SHARE","session":"5"}}
{"timestamp":"2019-09-13T20:12:34.821758471Z","level":"debug","source":"atc","message":"atc.log-conn.atc.log-conn.buildEventSource-collectEvents","data":{"duration":"588.502µs","query":"SELECT type, versio
@edtan
edtan / web.log
Last active September 13, 2019 01:09
Concourse web logs showing more detailed db queries, including queries within transactions. The log message is a bit strange, since queries within transactions are logged differently than queries not in transactions
Get Step
{"timestamp":"2019-09-13T00:26:17.358330970Z","level":"info","source":"atc","message":"atc.build-tracker.track.get-step.initializing","data":{"build":2,"job":"test","job-id":1,"pipeline":"simple","session":"18.11.3","step-name":"git-repo"}}
{"timestamp":"2019-09-13T00:26:17.360499539Z","level":"debug","source":"atc","message":"atc.db.ResourceConfigDescriptor-findOrCreate.query-row","data":{"duration":"1.236034ms","query":"SELECT id, unique_version_history FROM base_resource_types WHERE name = $1 FOR SHARE","session":"5"}}
{"timestamp":"2019-09-13T00:26:17.361267314Z","level":"debug","source":"atc","message":"atc.db.ResourceConfigDescriptor-findWithParentID.query-row","data":{"duration":"560.326µs","query":"SELECT id FROM resource_configs WHERE base_resource_type_id = $1 AND source_hash = $2 AND (1=1) FOR SHARE","session":"5"}}
{"timestamp":"2019-09-13T00:26:17.363723982Z","level":"debug","source":"atc","message":"atc.db.ResourceCacheDescriptor-findWithResourceConfig.query-row","data":{"duration":"1.
@edtan
edtan / web.log
Created August 23, 2019 16:40
Concourse web logs showing db queries for get-step and task-step
web_1_da9eccd0ef92 | {"timestamp":"2019-08-23T16:36:14.117795659Z","level":"debug","source":"atc","message":"atc.build-tracker.track.lock.acquire.acquired","data":{"build":8,"build_id":8,"id":[1,8],"job":"test","pipeline":"simple","session":"18.239.1.1"}}
web_1_da9eccd0ef92 | {"timestamp":"2019-08-23T16:36:14.232974783Z","level":"debug","source":"atc","message":"atc.log-conn.atc.pipelines.radar.scan-resource.interval-runner.found-created-container-in-db.query-row","data":{"duration":"114.352104ms","query":"SELECT b.id, b.name, b.job_id, b.team_id, b.status, b.manually_triggered, b.scheduled, b.schema, b.private_plan, b.public_plan, b.create_time, b.start_time, b.end_time, b.reap_time, j.name, b.pipeline_id, p.name, t.name, b.nonce, b.drained, b.aborted, b.completed FROM builds b LEFT OUTER JOIN jobs j ON b.job_id = j.id LEFT OUTER JOIN pipelines p ON b.pipeline_id = p.id LEFT OUTER JOIN teams t ON b.team_id = t.id WHERE b.id = $1","session":"6"}}
web_1_da9eccd0ef92 | {"timestamp":"2
@edtan
edtan / web.remote-db.log
Created July 31, 2019 23:50
Concourse issue 4162 - docker-compose setup pointing to remote db
web_1_ad4d56af92b3 | {"timestamp":"2019-07-31T23:20:00.006883824Z","level":"debug","source":"atc","message":"atc.log-conn.query","data":{"duration":"250.389031ms","query":"SELECT j.name, j.id FROM jobs j WHERE j.pipeline_id = $1","session":"6"}}
web_1_ad4d56af92b3 | {"timestamp":"2019-07-31T23:20:00.014160648Z","level":"debug","source":"atc","message":"atc.build-log-collector.tick.acquire.acquired","data":{"id":[3,997540461],"session":"22.2.1"}}
web_1_ad4d56af92b3 | {"timestamp":"2019-07-31T23:20:00.014258640Z","level":"debug","source":"atc","message":"atc.build-log-collector.tick.build-reaper.start","data":{"session":"22.2.2"}}
web_1_ad4d56af92b3 | {"timestamp":"2019-07-31T23:20:00.140834281Z","level":"debug","source":"atc","message":"atc.log-conn.query","data":{"duration":"126.473536ms","query":"SELECT p.id, p.name, p.groups, p.version, p.team_id, t.name, p.paused, p.public FROM pipelines p LEFT JOIN teams t ON p.team_id = t.id ORDER BY ordering","session":"6"}}
web_
@edtan
edtan / web.local.log
Created July 31, 2019 23:49
Concourse issue 4162 - normal local docker-compose setup
web_1_ad4d56af92b3 | {"timestamp":"2019-07-31T23:25:30.000748231Z","level":"debug","source":"atc","message":"atc.log-conn.exec","data":{"query":"UPDATE resource_config_scopes SET check_error = $1 WHERE id = $2","session":"6"}}
web_1_ad4d56af92b3 | {"timestamp":"2019-07-31T23:25:30.003142182Z","level":"debug","source":"atc","message":"atc.log-conn.exec","data":{"duration":"2.390545ms","query":"UPDATE resource_config_scopes SET check_error = $1 WHERE id = $2","session":"6"}}
web_1_ad4d56af92b3 | {"timestamp":"2019-07-31T23:25:30.003206294Z","level":"debug","source":"atc","message":"atc.pipelines.radar.scan-resource.interval-runner.no-new-versions","data":{"pipeline":"simple","resource":"git-repo","session":"17.1.1.1","team":"main"}}
web_1_ad4d56af92b3 | {"timestamp":"2019-07-31T23:25:30.005002252Z","level":"debug","source":"atc","message":"atc.pipelines.radar.scan-resource.interval-runner.release.released","data":{"id":[0,1],"pipeline":"simple","resource":"git-repo","session"
@edtan
edtan / breakpoint-for-db-opens.log
Created July 31, 2019 23:33
Concourse issue 4162 - connectionRetryingDriver breakpoint
> github.com/concourse/concourse/atc/db.(*connectionRetryingDriver).Open.func1() ./atc/db/connection_retrying_driver.go:44 (hits goroutine(16239):1 total:32) (PC: 0xba3d99)
39: func (d *connectionRetryingDriver) Open(name string) (driver.Conn, error) {
40: var conn driver.Conn
41:
42: err := backoff.Retry(func() error {
43: var err error
=> 44: if d.driverName == "postgres" {
45: conn, err = pq.DialOpen(keepAliveDialer{}, name)
46: } else {
47: conn, err = d.Driver.Open(name)
@edtan
edtan / go-mutex.log
Created July 24, 2019 17:17
Concourse Troubleshooting
--- mutex:
cycles/second=2711977886
sampling period=1
8756425368 10 @ 0x486e8e 0xa1929e 0xa18b91 0xdf3149 0xc87a52 0xc8787f 0x47cbb1
# 0x486e8d sync.(*Mutex).Unlock+0xed /usr/local/go/src/sync/mutex.go:201
# 0xa1929d github.com/concourse/concourse/atc/db/lock.(*lock).Acquire+0x5bd /src/atc/db/lock/lock.go:179
# 0xa18b90 github.com/concourse/concourse/atc/db/lock.(*lockFactory).Acquire+0x1c0 /src/atc/db/lock/lock.go:116
# 0xdf3148 github.com/concourse/concourse/atc/lockrunner.NewRunner.func1+0x338 /src/atc/lockrunner/runner.go:41
# 0xc87a51 github.com/tedsuo/ifrit.RunFunc.Run+0x41 /go/pkg/mod/github.com/tedsuo/ifrit@v0.0.0-20180802180643-bea94bb476cc/runner.go:36
# 0xc8787e github.com/tedsuo/ifrit.(*process).run+0x6e /go/pkg/mod/github.com/tedsuo/ifrit@v0.0.0-20180802180643-bea94bb476cc/process.go:71
@edtan
edtan / keybase.md
Created July 17, 2019 14:54
Keybase identity

Keybase proof

I hereby claim:

  • I am edtan on github.
  • I am edtan (https://keybase.io/edtan) on keybase.
  • I have a public key ASCKZKLzvsosng8gSzSRMc6HTqfptH_RU1g2iFCW2pB8jAo

To claim this, I am signing this object:

@edtan
edtan / resourcesQuery.sql
Created January 30, 2019 16:33
resourcesQuery used for testing https://github.com/concourse/concourse/issues/2814
select r.id, r.name, r.config, r.check_error, rs.last_checked, r.pipeline_id, r.nonce, r.resource_config_id, r.resource_config_scope_id, p.name, t.name, rs.check_error, r.api_pinned_version, r.pin_comment
from resources r
join pipelines p ON p.id = r.pipeline_id
join teams t ON t.id = p.team_id
left join resource_config_scopes rs ON r.resource_config_scope_id = rs.id
where r.active = true;
@edtan
edtan / resource-order.yml
Created January 30, 2019 16:32
Pipeline used for testing https://github.com/concourse/concourse/issues/2814
resource_types:
- name: time
type: registry-image
source:
repository: concourse/time-resource
resources:
- name: a
type: time
source: