func (event HTTPReponseTime) Emit(logger lager.Logger) {
state := "ok"
if event.Duration > 100*time.Millisecond {
state = "warning"
}
if event.Duration > 1*time.Second {
state = "critical"
}
emit(
logger.Session("http-response-time", lager.Data{
"route": event.Route,
"path": event.Path,
"duration": event.Duration.String(),
}),
goryman.Event{
Service: "http response time",
Metric: ms(event.Duration),
State: state,
Attributes: map[string]string{
"route": event.Route,
"path": event.Path,
},
},
)
}
func (engine *execEngine) LookupBuild(logger lager.Logger, model db.Build) (Build, error) {
var metadata execMetadata
err := json.Unmarshal([]byte(model.EngineMetadata), &metadata)
if err != nil {
logger.Error("invalid-metadata", err)
return nil, err
}
err = atc.NewPlanTraversal(engine.convertPipelineNameToID).Traverse(&metadata.Plan)
if err != nil {
return nil, err
}
return &execBuild{
buildID: model.ID,
stepMetadata: buildMetadata(model, engine.externalURL),
db: engine.db,
factory: engine.factory,
delegate: engine.delegateFactory.Delegate(model.ID, model.PipelineID),
metadata: metadata,
signals: make(chan os.Signal, 1),
}, nil
}
func configure(logger lager.Logger) (*ssh.ServerConfig, error) {
errorStrings := []string{}
sshConfig := &ssh.ServerConfig{}
key, err := acquireHostKey(logger)
if err != nil {
logger.Error("failed-to-acquire-host-key", err)
errorStrings = append(errorStrings, err.Error())
}
sshConfig.AddHostKey(key)
sshConfig.NoClientAuth = *allowUnauthenticatedClients
if *authorizedKey == "" && !*allowUnauthenticatedClients {
logger.Error("authorized-key-required", nil)
errorStrings = append(errorStrings, "Public user key is required")
}
if *authorizedKey != "" {
decodedPublicKey, err := decodeAuthorizedKey(logger)
if err == nil {
authenticator := authenticators.NewPublicKeyAuthenticator(decodedPublicKey)
sshConfig.PublicKeyCallback = authenticator.Authenticate
} else {
errorStrings = append(errorStrings, err.Error())
}
}
err = nil
if len(errorStrings) > 0 {
err = errors.New(strings.Join(errorStrings, ", "))
}
return sshConfig, err
}
func (db *ETCDDB) batchDeleteTasks(taskGuids []string, logger lager.Logger) {
if len(taskGuids) == 0 {
return
}
works := []func(){}
for _, taskGuid := range taskGuids {
taskGuid := taskGuid
works = append(works, func() {
_, err := db.client.Delete(taskGuid, true)
if err != nil {
logger.Error("failed-to-delete", err, lager.Data{
"task-guid": taskGuid,
})
}
})
}
throttler, err := workpool.NewThrottler(db.convergenceWorkersSize, works)
if err != nil {
logger.Error("failed-to-create-throttler", err)
}
throttler.Work()
return
}
func (db *SQLDB) countTasksByState(logger lager.Logger, q Queryable) (pendingCount, runningCount, completedCount, resolvingCount int) {
var query string
switch db.flavor {
case Postgres:
query = `
SELECT
COUNT(*) FILTER (WHERE state = $1) AS pending_tasks,
COUNT(*) FILTER (WHERE state = $2) AS running_tasks,
COUNT(*) FILTER (WHERE state = $3) AS completed_tasks,
COUNT(*) FILTER (WHERE state = $4) AS resolving_tasks
FROM tasks
`
case MySQL:
query = `
SELECT
COUNT(IF(state = ?, 1, NULL)) AS pending_tasks,
COUNT(IF(state = ?, 1, NULL)) AS running_tasks,
COUNT(IF(state = ?, 1, NULL)) AS completed_tasks,
COUNT(IF(state = ?, 1, NULL)) AS resolving_tasks
FROM tasks
`
default:
// totally shouldn't happen
panic("database flavor not implemented: " + db.flavor)
}
row := db.db.QueryRow(query, models.Task_Pending, models.Task_Running, models.Task_Completed, models.Task_Resolving)
err := row.Scan(&pendingCount, &runningCount, &completedCount, &resolvingCount)
if err != nil {
logger.Error("failed-counting-tasks", err)
}
return
}
func (tc *CCTaskClient) FailTask(logger lager.Logger, taskState *cc_messages.CCTaskState, httpClient *http.Client) error {
taskGuid := taskState.TaskGuid
payload, err := json.Marshal(cc_messages.TaskFailResponseForCC{
TaskGuid: taskGuid,
Failed: true,
FailureReason: "Unable to determine completion status",
})
if err != nil {
logger.Error("failed-to-marshal", err, lager.Data{"task_guid": taskGuid})
return err
}
req, err := http.NewRequest("POST", taskState.CompletionCallbackUrl, bytes.NewReader(payload))
if err != nil {
return err
}
req.Header.Set("Content-Type", "application/json")
resp, err := httpClient.Do(req)
if err != nil {
return err
}
defer resp.Body.Close()
if resp.StatusCode != http.StatusOK {
logger.Error("bad-response-from-cc", err, lager.Data{"task_guid": taskGuid})
return errors.New("received bad response from CC ")
}
return nil
}
func NewActualLRPHandler(bbs bbs.Client, legacyBBS Bbs.ReceptorBBS, logger lager.Logger) *ActualLRPHandler {
return &ActualLRPHandler{
bbs: bbs,
legacyBBS: legacyBBS,
logger: logger.Session("actual-lrp-handler"),
}
}
func New(timeout time.Duration, skipSSLVerification bool, logger lager.Logger) Uploader {
transport := &http.Transport{
Proxy: http.ProxyFromEnvironment,
Dial: (&net.Dialer{
Timeout: 10 * time.Second,
KeepAlive: 30 * time.Second,
}).Dial,
TLSHandshakeTimeout: 10 * time.Second,
TLSClientConfig: &tls.Config{
InsecureSkipVerify: skipSSLVerification,
MinVersion: tls.VersionTLS10,
},
}
httpClient := &http.Client{
Transport: transport,
Timeout: timeout,
}
return &URLUploader{
httpClient: httpClient,
transport: transport,
logger: logger.Session("URLUploader"),
}
}
func NewPoller(logger lager.Logger, httpClient *http.Client, pollInterval time.Duration) Poller {
return &poller{
client: httpClient,
pollInterval: pollInterval,
logger: logger.Session("poller"),
}
}
func (*generator) Guid(logger lager.Logger) string {
guid, err := uuid.NewV4()
if err != nil {
logger.Fatal("failed-to-generate-guid", err)
}
return guid.String()
}
func NewHandler(
logger lager.Logger,
webcamHost string,
) Handler {
director := func(req *http.Request) {
req.URL.Scheme = "http"
req.URL.Host = webcamHost
req.URL.Path = "/"
req.URL.RawQuery = "action=stream"
}
flushInterval, err := time.ParseDuration("10ms")
if err != nil {
logger.Fatal("golang broke", err)
}
proxy := httputil.ReverseProxy{
Director: director,
FlushInterval: flushInterval,
ErrorLog: log.New(ioutil.Discard, "", 0),
}
return &handler{
logger: logger,
proxy: proxy,
}
}
func (db *ETCDDB) resolveRestartableCrashedActualLRPS(logger lager.Logger, actualLRP *models.ActualLRP, starts *startRequests) func() {
return func() {
actualKey := actualLRP.ActualLRPKey
logger = logger.Session("restart-crash", lager.Data{
"process_guid": actualKey.ProcessGuid,
"index": actualKey.Index,
})
if actualLRP.State != models.ActualLRPStateCrashed {
logger.Error("failed-actual-lrp-state-is-not-crashed", nil)
return
}
logger.Debug("unclaiming-actual-lrp", lager.Data{"process_guid": actualLRP.ActualLRPKey.ProcessGuid, "index": actualLRP.ActualLRPKey.Index})
_, err := db.unclaimActualLRP(logger, &actualLRP.ActualLRPKey, &actualLRP.ActualLRPInstanceKey)
if err != nil {
logger.Error("failed-unclaiming-crash", err)
return
}
logger.Debug("succeeded-unclaiming-actual-lrp")
starts.Add(logger, &actualKey)
}
}
func (s *Scheduler) TryNextPendingBuild(logger lager.Logger, job atc.JobConfig, resources atc.ResourceConfigs) Waiter {
logger = logger.Session("try-next-pending")
wg := new(sync.WaitGroup)
wg.Add(1)
go func() {
defer wg.Done()
build, err := s.PipelineDB.GetNextPendingBuild(job.Name)
if err != nil {
if err == db.ErrNoBuild {
return
}
logger.Error("failed-to-get-next-pending-build", err)
return
}
s.scheduleAndResumePendingBuild(logger, build, job, resources)
}()
return wg
}
func (event SchedulingJobDuration) Emit(logger lager.Logger) {
state := "ok"
if event.Duration > time.Second {
state = "warning"
}
if event.Duration > 5*time.Second {
state = "critical"
}
emit(
logger.Session("job-scheduling-duration", lager.Data{
"pipeline": event.PipelineName,
"job": event.JobName,
"duration": event.Duration.String(),
}),
goryman.Event{
Service: "scheduling: job duration (ms)",
Metric: ms(event.Duration),
State: state,
Attributes: map[string]string{
"pipeline": event.PipelineName,
"job": event.JobName,
},
},
)
}
func (db *serviceClient) Cells(logger lager.Logger) (models.CellSet, error) {
kvPairs, _, err := db.consulClient.KV().List(CellSchemaRoot(), nil)
if err != nil {
bbsErr := models.ConvertError(convertConsulError(err))
if bbsErr.Type != models.Error_ResourceNotFound {
return nil, bbsErr
}
}
if kvPairs == nil {
err = consuladapter.NewPrefixNotFoundError(CellSchemaRoot())
bbsErr := models.ConvertError(convertConsulError(err))
if bbsErr.Type != models.Error_ResourceNotFound {
return nil, bbsErr
}
}
cellPresences := models.NewCellSet()
for _, kvPair := range kvPairs {
if kvPair.Session == "" {
continue
}
cell := kvPair.Value
presence := new(models.CellPresence)
err := models.FromJSON(cell, presence)
if err != nil {
logger.Error("failed-to-unmarshal-cells-json", err)
continue
}
cellPresences.Add(presence)
}
return cellPresences, nil
}
func (b *Bulker) sync(logger lager.Logger) {
logger = logger.Session("sync")
logger.Info("starting")
defer logger.Info("finished")
startTime := b.clock.Now()
ops, batchError := b.generator.BatchOperations(logger)
endTime := b.clock.Now()
sendError := repBulkSyncDuration.Send(endTime.Sub(startTime))
if sendError != nil {
logger.Error("failed-to-send-rep-bulk-sync-duration-metric", sendError)
}
if batchError != nil {
logger.Error("failed-to-generate-operations", batchError)
return
}
for _, operation := range ops {
b.queue.Push(operation)
}
}
func New(natsClient diegonats.NATSClient, workPool *workpool.WorkPool, logger lager.Logger) NATSEmitter {
return &natsEmitter{
natsClient: natsClient,
workPool: workPool,
logger: logger.Session("nats-emitter"),
}
}
func (db *ETCDDB) UnclaimActualLRP(logger lager.Logger, key *models.ActualLRPKey) (*models.ActualLRPGroup, *models.ActualLRPGroup, error) {
actualLRP, modifiedIndex, err := db.rawActualLRPByProcessGuidAndIndex(logger, key.ProcessGuid, key.Index)
bbsErr := models.ConvertError(err)
if bbsErr != nil {
return nil, nil, bbsErr
}
beforeActualLRP := *actualLRP
if actualLRP.State == models.ActualLRPStateUnclaimed {
logger.Debug("already-unclaimed")
return nil, nil, models.ErrActualLRPCannotBeUnclaimed
}
actualLRP.State = models.ActualLRPStateUnclaimed
actualLRP.ActualLRPKey = *key
actualLRP.ActualLRPInstanceKey = models.ActualLRPInstanceKey{}
actualLRP.ActualLRPNetInfo = models.EmptyActualLRPNetInfo()
actualLRP.Since = db.clock.Now().UnixNano()
actualLRP.ModificationTag.Increment()
data, err := db.serializeModel(logger, actualLRP)
if err != nil {
return nil, nil, err
}
_, err = db.client.CompareAndSwap(ActualLRPSchemaPath(key.ProcessGuid, key.Index), data, 0, modifiedIndex)
if err != nil {
logger.Error("failed-compare-and-swap", err)
return nil, nil, ErrorFromEtcdError(logger, err)
}
return &models.ActualLRPGroup{Instance: &beforeActualLRP}, &models.ActualLRPGroup{Instance: actualLRP}, nil
}
func getDockerRegistryServices(consulCluster string, backendLogger lager.Logger) ([]consulServiceInfo, error) {
logger := backendLogger.Session("docker-registry-consul-services")
response, err := http.Get(consulCluster + "/v1/catalog/service/docker-registry")
if err != nil {
return nil, err
}
defer response.Body.Close()
body, err := ioutil.ReadAll(response.Body)
if err != nil {
return nil, err
}
var ips []consulServiceInfo
err = json.Unmarshal(body, &ips)
if err != nil {
return nil, err
}
if len(ips) == 0 {
return nil, ErrMissingDockerRegistry
}
logger.Debug("docker-registry-consul-services", lager.Data{"ips": ips})
return ips, nil
}
func (db *ETCDDB) FailActualLRP(logger lager.Logger, key *models.ActualLRPKey, errorMessage string) (*models.ActualLRPGroup, *models.ActualLRPGroup, error) {
logger = logger.WithData(lager.Data{"actual_lrp_key": key, "error_message": errorMessage})
logger.Info("starting")
lrp, prevIndex, err := db.rawActualLRPByProcessGuidAndIndex(logger, key.ProcessGuid, key.Index)
if err != nil {
logger.Error("failed-to-get-actual-lrp", err)
return nil, nil, err
}
beforeActualLRP := *lrp
if lrp.State != models.ActualLRPStateUnclaimed {
return nil, nil, models.ErrActualLRPCannotBeFailed
}
lrp.ModificationTag.Increment()
lrp.PlacementError = errorMessage
lrp.Since = db.clock.Now().UnixNano()
lrpData, serialErr := db.serializeModel(logger, lrp)
if serialErr != nil {
return nil, nil, serialErr
}
_, err = db.client.CompareAndSwap(ActualLRPSchemaPath(key.ProcessGuid, key.Index), lrpData, 0, prevIndex)
if err != nil {
logger.Error("failed", err)
return nil, nil, models.ErrActualLRPCannotBeFailed
}
logger.Info("succeeded")
return &models.ActualLRPGroup{Instance: &beforeActualLRP}, &models.ActualLRPGroup{Instance: lrp}, nil
}
func initializeDropsonde(logger lager.Logger) {
dropsondeDestination := fmt.Sprint("localhost:", *dropsondePort)
err := dropsonde.Initialize(dropsondeDestination, dropsondeOrigin)
if err != nil {
logger.Error("failed to initialize dropsonde: %v", err)
}
}
func (db *ETCDDB) rawActualLRPGroupByProcessGuidAndIndex(logger lager.Logger, processGuid string, index int32) (*models.ActualLRPGroup, error) {
node, err := db.fetchRecursiveRaw(logger, ActualLRPIndexDir(processGuid, index))
if err != nil {
return nil, err
}
group := models.ActualLRPGroup{}
for _, instanceNode := range node.Nodes {
var lrp models.ActualLRP
deserializeErr := db.deserializeModel(logger, instanceNode, &lrp)
if deserializeErr != nil {
logger.Error("failed-parsing-actual-lrp", deserializeErr, lager.Data{"key": instanceNode.Key})
return nil, deserializeErr
}
if isInstanceActualLRPNode(instanceNode) {
group.Instance = &lrp
}
if isEvacuatingActualLRPNode(instanceNode) {
group.Evacuating = &lrp
}
}
if group.Evacuating == nil && group.Instance == nil {
return nil, models.ErrResourceNotFound
}
return &group, nil
}
func ProxyRequests(logger lager.Logger, channelType string, reqs <-chan *ssh.Request, channel ssh.Channel) {
logger = logger.Session("proxy-requests", lager.Data{
"channel-type": channelType,
})
logger.Info("started")
defer logger.Info("completed")
defer channel.Close()
for req := range reqs {
logger.Info("request", lager.Data{
"type": req.Type,
"wantReply": req.WantReply,
"payload": req.Payload,
})
success, err := channel.SendRequest(req.Type, req.WantReply, req.Payload)
if err != nil {
logger.Error("send-request-failed", err)
continue
}
if req.WantReply {
req.Reply(success, nil)
}
}
}
func (db *ETCDDB) createActualLRP(logger lager.Logger, desiredLRP *models.DesiredLRP, index int32) error {
logger = logger.Session("create-actual-lrp")
var err error
if index >= desiredLRP.Instances {
err = models.NewError(models.Error_InvalidRecord, "Index too large")
logger.Error("actual-lrp-index-too-large", err, lager.Data{"actual_index": index, "desired_instances": desiredLRP.Instances})
return err
}
guid, err := uuid.NewV4()
if err != nil {
return err
}
actualLRP := &models.ActualLRP{
ActualLRPKey: models.NewActualLRPKey(
desiredLRP.ProcessGuid,
index,
desiredLRP.Domain,
),
State: models.ActualLRPStateUnclaimed,
Since: db.clock.Now().UnixNano(),
ModificationTag: models.ModificationTag{
Epoch: guid.String(),
Index: 0,
},
}
err = db.createRawActualLRP(logger, actualLRP)
if err != nil {
return err
}
return nil
}
func (build *execBuild) Resume(logger lager.Logger) {
stepFactory := build.buildStepFactory(logger, build.metadata.Plan)
source := stepFactory.Using(&exec.NoopStep{}, exec.NewSourceRepository())
defer source.Release()
process := ifrit.Background(source)
exited := process.Wait()
aborted := false
var succeeded exec.Success
for {
select {
case err := <-exited:
if aborted {
succeeded = false
} else if !source.Result(&succeeded) {
logger.Error("step-had-no-result", errors.New("step failed to provide us with a result"))
succeeded = false
}
build.delegate.Finish(logger.Session("finish"), err, succeeded, aborted)
return
case sig := <-build.signals:
process.Signal(sig)
if sig == os.Kill {
aborted = true
}
}
}
}
func NewHandler(
logger lager.Logger,
pipelineDBFactory db.PipelineDBFactory,
pipelineHandler func(db.PipelineDB) http.Handler,
template *template.Template,
) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
pipelineDB, err := pipelineDBFactory.BuildDefault()
if err != nil {
if err == db.ErrNoPipelines {
err = template.Execute(w, TemplateData{})
if err != nil {
log.Fatal("failed-to-task-template", err, lager.Data{})
}
return
}
logger.Error("failed-to-load-pipelinedb", err)
w.WriteHeader(http.StatusInternalServerError)
return
}
pipelineHandler(pipelineDB).ServeHTTP(w, r)
})
}
func NewCellHandler(logger lager.Logger, serviceClient bbs.ServiceClient, exitChan chan<- struct{}) *CellHandler {
return &CellHandler{
logger: logger.Session("cell-handler"),
serviceClient: serviceClient,
exitChan: exitChan,
}
}
func (db *serviceClient) CellEvents(logger lager.Logger) <-chan models.CellEvent {
logger = logger.Session("cell-events")
disappearanceWatcher, disappeared := locket.NewDisappearanceWatcher(logger, db.consulClient, CellSchemaRoot(), db.clock)
process := ifrit.Invoke(disappearanceWatcher)
events := make(chan models.CellEvent)
go func() {
for {
select {
case keys, ok := <-disappeared:
if !ok {
process.Signal(os.Interrupt)
return
}
cellIDs := make([]string, len(keys))
for i, key := range keys {
cellIDs[i] = path.Base(key)
}
logger.Info("cell-disappeared", lager.Data{"cell_ids": cellIDs})
events <- models.NewCellDisappearedEvent(cellIDs)
}
}
}()
return events
}
func (s *Scheduler) TriggerImmediately(logger lager.Logger, job atc.JobConfig, resources atc.ResourceConfigs, resourceTypes atc.ResourceTypes) (db.Build, Waiter, error) {
logger = logger.Session("trigger-immediately")
build, err := s.PipelineDB.CreateJobBuild(job.Name)
if err != nil {
logger.Error("failed-to-create-build", err)
return db.Build{}, nil, err
}
jobService, err := NewJobService(job, s.PipelineDB, s.Scanner)
if err != nil {
return db.Build{}, nil, err
}
wg := new(sync.WaitGroup)
wg.Add(1)
// do not block request on scanning input versions
go func() {
defer wg.Done()
s.ScheduleAndResumePendingBuild(logger, nil, build, job, resources, resourceTypes, jobService)
}()
return build, wg, nil
}
func connectToNatsServer(logger lager.Logger, c *config.Config) *nats.Conn {
var natsClient *nats.Conn
var err error
natsServers := c.NatsServers()
attempts := 3
for attempts > 0 {
options := nats.DefaultOptions
options.Servers = natsServers
options.PingInterval = c.NatsClientPingInterval
options.ClosedCB = func(conn *nats.Conn) {
logger.Fatal("nats-connection-closed", errors.New("unexpected close"), lager.Data{"last_error": conn.LastError()})
}
natsClient, err = options.Connect()
if err == nil {
break
} else {
attempts--
time.Sleep(100 * time.Millisecond)
}
}
if err != nil {
logger.Fatal("nats-connection-error", err)
}
return natsClient
}