From d7a123fcd44c28f4827b81078b08222c910ebc04 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Wed, 17 Feb 2016 10:28:42 +0100 Subject: [PATCH] Keep track of the time we spend copying to/from build machines --- src/hydra-queue-runner/build-remote.cc | 14 ++++++++++++++ src/hydra-queue-runner/builder.cc | 9 +++++---- src/hydra-queue-runner/hydra-queue-runner.cc | 10 ++++++---- src/hydra-queue-runner/state.hh | 4 +++- src/lib/Hydra/Schema/BuildSteps.pm | 11 +++++++++-- src/sql/hydra.sql | 3 +++ src/sql/upgrade-45.sql | 1 + 7 files changed, 41 insertions(+), 11 deletions(-) create mode 100644 src/sql/upgrade-45.sql diff --git a/src/hydra-queue-runner/build-remote.cc b/src/hydra-queue-runner/build-remote.cc index 39d041d9..787bf43f 100644 --- a/src/hydra-queue-runner/build-remote.cc +++ b/src/hydra-queue-runner/build-remote.cc @@ -229,7 +229,14 @@ void State::buildRemote(ref store, mc1.reset(); MaintainCount mc2(nrStepsCopyingTo); printMsg(lvlDebug, format("sending closure of ‘%1%’ to ‘%2%’") % step->drvPath % machine->sshName); + + auto now1 = std::chrono::steady_clock::now(); + copyClosureTo(store, from, to, inputs, bytesSent); + + auto now2 = std::chrono::steady_clock::now(); + + result.overhead += std::chrono::duration_cast(now2 - now1).count(); } autoDelete.cancel(); @@ -283,7 +290,14 @@ void State::buildRemote(ref store, for (auto & output : step->drv.outputs) outputs.insert(output.second.path); MaintainCount mc(nrStepsCopyingFrom); + + auto now1 = std::chrono::steady_clock::now(); + copyClosureFrom(store, from, to, outputs, bytesReceived); + + auto now2 = std::chrono::steady_clock::now(); + + result.overhead += std::chrono::duration_cast(now2 - now1).count(); } /* Shut down the connection. */ diff --git a/src/hydra-queue-runner/builder.cc b/src/hydra-queue-runner/builder.cc index 9d1fd0dc..557ccde9 100644 --- a/src/hydra-queue-runner/builder.cc +++ b/src/hydra-queue-runner/builder.cc @@ -165,7 +165,7 @@ bool State::doBuildStep(nix::ref store, Step::ptr step, } if (retry) { pqxx::work txn(*conn); - finishBuildStep(txn, result.startTime, result.stopTime, build->id, + finishBuildStep(txn, result.startTime, result.stopTime, result.overhead, build->id, stepNr, machine->sshName, bssAborted, result.errorMsg); txn.commit(); if (quit) exit(1); @@ -214,7 +214,8 @@ bool State::doBuildStep(nix::ref store, Step::ptr step, { pqxx::work txn(*conn); - finishBuildStep(txn, result.startTime, result.stopTime, build->id, stepNr, machine->sshName, bssSuccess); + finishBuildStep(txn, result.startTime, result.stopTime, result.overhead, + build->id, stepNr, machine->sshName, bssSuccess); for (auto & b : direct) markSucceededBuild(txn, b, res, build != b || result.status != BuildResult::Built, @@ -334,8 +335,8 @@ bool State::doBuildStep(nix::ref store, Step::ptr step, } if (!cachedFailure) - finishBuildStep(txn, result.startTime, result.stopTime, build->id, - stepNr, machine->sshName, buildStepStatus, result.errorMsg); + finishBuildStep(txn, result.startTime, result.stopTime, result.overhead, + build->id, stepNr, machine->sshName, buildStepStatus, result.errorMsg); /* Mark all builds that depend on this derivation as failed. */ for (auto & build2 : indirect) { diff --git a/src/hydra-queue-runner/hydra-queue-runner.cc b/src/hydra-queue-runner/hydra-queue-runner.cc index 4d1146f5..11709c31 100644 --- a/src/hydra-queue-runner/hydra-queue-runner.cc +++ b/src/hydra-queue-runner/hydra-queue-runner.cc @@ -204,18 +204,20 @@ int State::createBuildStep(pqxx::work & txn, time_t startTime, Build::ptr build, } -void State::finishBuildStep(pqxx::work & txn, time_t startTime, time_t stopTime, BuildID buildId, int stepNr, - const std::string & machine, BuildStepStatus status, const std::string & errorMsg, BuildID propagatedFrom) +void State::finishBuildStep(pqxx::work & txn, time_t startTime, time_t stopTime, unsigned int overhead, + BuildID buildId, int stepNr, const std::string & machine, BuildStepStatus status, + const std::string & errorMsg, BuildID propagatedFrom) { assert(startTime); assert(stopTime); txn.parameterized - ("update BuildSteps set busy = 0, status = $1, propagatedFrom = $4, errorMsg = $5, startTime = $6, stopTime = $7, machine = $8 where build = $2 and stepnr = $3") + ("update BuildSteps set busy = 0, status = $1, propagatedFrom = $4, errorMsg = $5, startTime = $6, stopTime = $7, machine = $8, overhead = $9 where build = $2 and stepnr = $3") ((int) status)(buildId)(stepNr) (propagatedFrom, propagatedFrom != 0) (errorMsg, errorMsg != "") (startTime)(stopTime) - (machine, machine != "").exec(); + (machine, machine != "") + (overhead, overhead != 0).exec(); } diff --git a/src/hydra-queue-runner/state.hh b/src/hydra-queue-runner/state.hh index a296ddc7..9b710808 100644 --- a/src/hydra-queue-runner/state.hh +++ b/src/hydra-queue-runner/state.hh @@ -49,6 +49,7 @@ typedef enum { struct RemoteResult : nix::BuildResult { time_t startTime = 0, stopTime = 0; + unsigned int overhead = 0; nix::Path logFile; bool canRetry() @@ -363,7 +364,8 @@ private: const std::string & machine, BuildStepStatus status, const std::string & errorMsg = "", BuildID propagatedFrom = 0); - void finishBuildStep(pqxx::work & txn, time_t startTime, time_t stopTime, BuildID buildId, int stepNr, + void finishBuildStep(pqxx::work & txn, time_t startTime, time_t stopTime, + unsigned int overhead, BuildID buildId, int stepNr, const std::string & machine, BuildStepStatus status, const std::string & errorMsg = "", BuildID propagatedFrom = 0); diff --git a/src/lib/Hydra/Schema/BuildSteps.pm b/src/lib/Hydra/Schema/BuildSteps.pm index 31f59f3e..aeb04a8f 100644 --- a/src/lib/Hydra/Schema/BuildSteps.pm +++ b/src/lib/Hydra/Schema/BuildSteps.pm @@ -98,6 +98,11 @@ __PACKAGE__->table("BuildSteps"); is_foreign_key: 1 is_nullable: 1 +=head2 overhead + + data_type: 'integer' + is_nullable: 1 + =cut __PACKAGE__->add_columns( @@ -125,6 +130,8 @@ __PACKAGE__->add_columns( { data_type => "text", is_nullable => 1 }, "propagatedfrom", { data_type => "integer", is_foreign_key => 1, is_nullable => 1 }, + "overhead", + { data_type => "integer", is_nullable => 1 }, ); =head1 PRIMARY KEY @@ -194,8 +201,8 @@ __PACKAGE__->belongs_to( ); -# Created by DBIx::Class::Schema::Loader v0.07033 @ 2015-02-25 16:27:20 -# DO NOT MODIFY THIS OR ANYTHING ABOVE! md5sum:ZbOxzCzFN7fIT9M2BFY0iQ +# Created by DBIx::Class::Schema::Loader v0.07043 @ 2016-02-16 18:04:52 +# DO NOT MODIFY THIS OR ANYTHING ABOVE! md5sum:TRALbEoaF/OIOyERYCyxkw my %hint = ( columns => [ diff --git a/src/sql/hydra.sql b/src/sql/hydra.sql index b627684d..c551e05e 100644 --- a/src/sql/hydra.sql +++ b/src/sql/hydra.sql @@ -273,6 +273,9 @@ create table BuildSteps ( propagatedFrom integer, + -- Time in milliseconds spend copying stuff from/to build machines. + overhead integer, + primary key (build, stepnr), foreign key (build) references Builds(id) on delete cascade, foreign key (propagatedFrom) references Builds(id) on delete cascade diff --git a/src/sql/upgrade-45.sql b/src/sql/upgrade-45.sql new file mode 100644 index 00000000..085fa9af --- /dev/null +++ b/src/sql/upgrade-45.sql @@ -0,0 +1 @@ +alter table BuildSteps add column overhead integer;