Automatic merge of gitlab-org/gitlab-ce master

doc/user/gitlab_com/index.md

@@ -43,13 +43,15 @@ Host gitlab.com
 
 Below are the settings for [GitLab Pages].
 
-| Setting                 | GitLab.com        | Default       |
-| ----------------------- | ----------------  | ------------- |
-| Domain name             | `gitlab.io`       | -             |
-| IP address              | `35.185.44.232`   | -             |
-| Custom domains support  | yes               | no            |
-| TLS certificates support| yes               | no            |
+| Setting                     | GitLab.com        | Default       |
+| --------------------------- | ----------------  | ------------- |
+| Domain name                 | `gitlab.io`       | -             |
+| IP address                  | `35.185.44.232`   | -             |
+| Custom domains support      | yes               | no            |
+| TLS certificates support    | yes               | no            |
+| Maximum size (uncompressed) | 1G                | 100M          |
 
+NOTE: **Note:**
 The maximum size of your Pages site is regulated by the artifacts maximum size
 which is part of [GitLab CI/CD](#gitlab-cicd).
 
@@ -59,7 +61,7 @@ Below are the current settings regarding [GitLab CI/CD](../../ci/README.md).
 
 | Setting                 | GitLab.com        | Default       |
 | -----------             | ----------------- | ------------- |
-| Artifacts maximum size  | 1G                | 100M          |
+| Artifacts maximum size (uncompressed) | 1G                | 100M          |
 | Artifacts [expiry time](../../ci/yaml/README.md#artifactsexpire_in)   | kept forever           | deleted after 30 days unless otherwise specified    |
 
 ## Repository size limit

lib/gitlab/sidekiq_logging/structured_logger.rb

@@ -8,16 +8,16 @@ module Gitlab
       MAXIMUM_JOB_ARGUMENTS_LENGTH = 10.kilobytes
 
       def call(job, queue)
-        started_at = current_time
+        started_time = get_time
         base_payload = parse_job(job)
 
-        Sidekiq.logger.info log_job_start(started_at, base_payload)
+        Sidekiq.logger.info log_job_start(base_payload)
 
         yield
 
-        Sidekiq.logger.info log_job_done(job, started_at, base_payload)
+        Sidekiq.logger.info log_job_done(job, started_time, base_payload)
       rescue => job_exception
-        Sidekiq.logger.warn log_job_done(job, started_at, base_payload, job_exception)
+        Sidekiq.logger.warn log_job_done(job, started_time, base_payload, job_exception)
 
         raise
       end
@@ -32,7 +32,7 @@ module Gitlab
         output_payload.merge!(job.slice(*::Gitlab::InstrumentationHelper::KEYS))
       end
 
-      def log_job_start(started_at, payload)
+      def log_job_start(payload)
         payload['message'] = "#{base_message(payload)}: start"
         payload['job_status'] = 'start'
 
@@ -45,11 +45,12 @@ module Gitlab
         payload
       end
 
-      def log_job_done(job, started_at, payload, job_exception = nil)
+      def log_job_done(job, started_time, payload, job_exception = nil)
         payload = payload.dup
         add_instrumentation_keys!(job, payload)
-        payload['duration'] = elapsed(started_at)
-        payload['completed_at'] = Time.now.utc
+
+        elapsed_time = elapsed(started_time)
+        add_time_keys!(elapsed_time, payload)
 
         message = base_message(payload)
 
@@ -69,6 +70,14 @@ module Gitlab
         payload
       end
 
+      def add_time_keys!(time, payload)
+        payload['duration'] = time[:duration].round(3)
+        payload['system_s'] = time[:stime].round(3)
+        payload['user_s'] = time[:utime].round(3)
+        payload['child_s'] = time[:ctime].round(3) if time[:ctime] > 0
+        payload['completed_at'] = Time.now.utc
+      end
+
       def parse_job(job)
         job = job.dup
 
@@ -93,8 +102,25 @@ module Gitlab
         (Time.now.utc - start).to_f.round(3)
       end
 
-      def elapsed(start)
-        (current_time - start).round(3)
+      def elapsed(t0)
+        t1 = get_time
+        {
+          duration: t1[:now] - t0[:now],
+          stime: t1[:times][:stime] - t0[:times][:stime],
+          utime: t1[:times][:utime] - t0[:times][:utime],
+          ctime: ctime(t1[:times]) - ctime(t0[:times])
+        }
+      end
+
+      def get_time
+        {
+          now: current_time,
+          times: Process.times
+        }
+      end
+
+      def ctime(times)
+        times[:cstime] + times[:cutime]
       end
 
       def current_time

spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb

@@ -36,7 +36,9 @@ describe Gitlab::SidekiqLogging::StructuredLogger do
         'message' => 'TestWorker JID-da883554ee4fe414012f5f42: done: 0.0 sec',
         'job_status' => 'done',
         'duration' => 0.0,
-        "completed_at" => timestamp.iso8601(3)
+        "completed_at" => timestamp.iso8601(3),
+        "system_s" => 0.0,
+        "user_s" => 0.0
       )
     end
     let(:exception_payload) do
@@ -52,6 +54,13 @@ describe Gitlab::SidekiqLogging::StructuredLogger do
       allow(Sidekiq).to receive(:logger).and_return(logger)
 
       allow(subject).to receive(:current_time).and_return(timestamp.to_f)
+
+      allow(Process).to receive(:times).and_return(
+        stime:  0.0,
+        utime:  0.0,
+        cutime: 0.0,
+        cstime: 0.0
+      )
     end
 
     subject { described_class.new }
@@ -177,5 +186,31 @@ describe Gitlab::SidekiqLogging::StructuredLogger do
         end
       end
     end
+
+    def ctime(times)
+      times[:cstime] + times[:cutime]
+    end
+
+    context 'with ctime value greater than 0' do
+      let(:times_start) { { stime: 0.04999, utime: 0.0483, cstime: 0.0188, cutime: 0.0188 } }
+      let(:times_end)   { { stime: 0.0699, utime: 0.0699, cstime: 0.0399, cutime: 0.0399 } }
+
+      before do
+        end_payload['system_s'] = 0.02
+        end_payload['user_s'] = 0.022
+        end_payload['child_s'] = 0.042
+
+        allow(Process).to receive(:times).and_return(times_start, times_end)
+      end
+
+      it 'logs with ctime data and other cpu data' do
+        Timecop.freeze(timestamp) do
+          expect(logger).to receive(:info).with(start_payload.except('args')).ordered
+          expect(logger).to receive(:info).with(end_payload.except('args')).ordered
+
+          subject.call(job, 'test_queue') { }
+        end
+      end
+    end
   end
 end