Merge from ci_feature to ci_feature prod

README.md

@@ -8,7 +8,31 @@ information see the [Code of Conduct FAQ](https://opensource.microsoft.com/codeo
 additional questions or comments.
 
 ## Release History
+
 Note : The agent version(s) below has dates (ciprod<mmddyyyy>), which indicate the agent build dates (not release dates)
+
+### 10/09/2018 - Version microsoft/oms:ciprod01092019
+- Omsagent - 1.8.1.256 (nov 2018 release)
+- Persist fluentbit state between container restarts
+- Populate 'TimeOfCommand' for agent ingest time for container logs
+- Get node cpu usage from cpuusagenanoseconds (and convert to cpuusgaenanocores)
+- Container Node Inventory - move to fluentD from OMI
+- Mount docker.sock (Daemon set) as /var/run/host
+- Liveness probe (Daemon set) - check for omsagent user permissions in docker.sock and update as necessary (required when docker daemon gets restarted)
+- Move to fixed type for kubeevents & kubeservices
+- Disable collecting ENV for our oms agent container (daemonset & replicaset)
+- Disable container inventory collection for 'sandbox' containers & non kubernetes managed containers
+- Agent telemetry - ContainerLogsAgentSideLatencyMs
+- Agent telemetry - PodCount
+- Agent telemetry - ControllerCount
+-	Agent telemetry - K8S Version
+- Agent telemetry - NodeCoreCapacity
+- Agent telemetry - NodeMemoryCapacity
+- Agent telemetry - KubeEvents (exceptions)
+- Agent telemetry - Kubenodes (exceptions)
+- Agent telemetry - kubepods (exceptions)
+- Agent telemetry - kubeservices (exceptions)
+- Agent telemetry - Daemonset , Replicaset as dimensions (bug fix)
 
 ### 11/29/2018 - Version microsoft/oms:ciprod11292018
 - Disable Container Image inventory workflow

installer/conf/container.conf

@@ -15,16 +15,6 @@
   log_level debug
 </source>
 
-# Container host inventory
-<source>
-	type omi
-	run_interval 60s
-	tag oms.api.ContainerNodeInventory
-	items [
-		["root/cimv2","Container_HostInventory"]
-	]
-</source>
-
 #cadvisor perf
 <source>
 	type cadvisorperf
@@ -33,19 +23,6 @@
   log_level debug
 </source>
 
-<match oms.api.ContainerNodeInventory**>
-  type out_oms_api
-  log_level debug
-  buffer_chunk_limit 20m
-  buffer_type file
-  buffer_path %STATE_DIR_WS%/out_oms_containernodeinventory*.buffer
-  buffer_queue_limit 20
-  flush_interval 20s
-  retry_limit 10
-  retry_wait 15s
-  max_retry_wait 9m
-</match>
-
 <match oms.containerinsights.containerinventory**>
   type out_oms
   log_level debug

installer/conf/kube.conf

@@ -11,7 +11,7 @@
 #Kubernetes events
 <source>
 	type kubeevents
-	tag oms.api.KubeEvents.CollectionTime
+	tag oms.containerinsights.KubeEvents
 	run_interval 60s
   log_level debug
 </source>
@@ -26,7 +26,7 @@
 #Kubernetes services
 <source>
 	type kubeservices
-	tag oms.api.KubeServices.CollectionTime
+	tag oms.containerinsights.KubeServices
 	run_interval 60s
   log_level debug
 </source>
@@ -62,18 +62,19 @@
   max_retry_wait 9m
 </match>
 
-<match oms.api.KubeEvents**>
-	type out_oms_api
+<match oms.containerinsights.KubeEvents**>
+	type out_oms
 	log_level debug
-  num_threads 5
+	num_threads 5
 	buffer_chunk_limit 5m
 	buffer_type file
-	buffer_path %STATE_DIR_WS%/out_oms_api_kubeevents*.buffer
+	buffer_path %STATE_DIR_WS%/out_oms_kubeevents*.buffer
 	buffer_queue_limit 10
-  buffer_queue_full_action drop_oldest_chunk
+	buffer_queue_full_action drop_oldest_chunk
 	flush_interval 20s
 	retry_limit 10
 	retry_wait 30s
+	max_retry_wait 9m
 </match>
 
 <match oms.api.KubeLogs**>
@@ -88,8 +89,8 @@
 	retry_wait 30s
 </match>
 
-<match oms.api.KubeServices**>	  
-  type out_oms_api
+<match oms.containerinsights.KubeServices**>
+  type out_oms
   log_level debug
   num_threads 5
   buffer_chunk_limit 20m
@@ -118,6 +119,19 @@
   max_retry_wait 9m
 </match>
 
+<match oms.api.ContainerNodeInventory**>
+  type out_oms_api
+  log_level debug
+  buffer_chunk_limit 20m
+  buffer_type file
+  buffer_path %STATE_DIR_WS%/out_oms_containernodeinventory*.buffer
+  buffer_queue_limit 20
+  flush_interval 20s
+  retry_limit 10
+  retry_wait 15s
+  max_retry_wait 9m
+</match>
+
 <match oms.api.KubePerf**>	
   type out_oms
   log_level debug

installer/conf/td-agent-bit.conf

@@ -8,7 +8,7 @@
     Name tail
     Tag oms.container.log.*
     Path /var/log/containers/*.log
-    DB /var/opt/microsoft/docker-cimprov/state/fblogs.db
+    DB /var/log/omsagent-fblogs.db
     Parser docker
     Mem_Buf_Limit 30m
     Path_Key filepath
@@ -28,5 +28,5 @@
     EnableTelemetry                 true
     TelemetryPushIntervalSeconds    300
     Match                           oms.container.log.*
-    AgentVersion                    ciprod11292018
+    AgentVersion                    ciprod01092019
 

source/code/go/src/plugins/oms.go

@@ -77,9 +77,10 @@ var (
 
 // DataItem represents the object corresponding to the json that is sent by fluentbit tail plugin
 type DataItem struct {
-	LogEntry          string `json:"LogEntry"`
-	LogEntrySource    string `json:"LogEntrySource"`
-	LogEntryTimeStamp string `json:"LogEntryTimeStamp"`
+	LogEntry          		string `json:"LogEntry"`
+	LogEntrySource    		string `json:"LogEntrySource"`
+	LogEntryTimeStamp 		string `json:"LogEntryTimeStamp"`
+	LogEntryTimeOfCommand	string `json:"TimeOfCommand"`
 	ID                string `json:"Id"`
 	Image             string `json:"Image"`
 	Name              string `json:"Name"`
@@ -204,6 +205,10 @@ func PostDataHelper(tailPluginRecords []map[interface{}]interface{}) int {
 
 	start := time.Now()
 	var dataItems []DataItem
+
+	var maxLatency float64
+	var maxLatencyContainer string
+
 	ignoreIDSet := make(map[string]bool)
 	imageIDMap := make(map[string]string)
 	nameIDMap := make(map[string]string)
@@ -248,18 +253,32 @@ func PostDataHelper(tailPluginRecords []map[interface{}]interface{}) int {
 			Log("ContainerId %s not present in Map ", containerID)
 		}
 
+
 		dataItem := DataItem{
-			ID:                stringMap["Id"],
-			LogEntry:          stringMap["LogEntry"],
-			LogEntrySource:    stringMap["LogEntrySource"],
-			LogEntryTimeStamp: stringMap["LogEntryTimeStamp"],
-			SourceSystem:      stringMap["SourceSystem"],
-			Computer:          Computer,
-			Image:             stringMap["Image"],
-			Name:              stringMap["Name"],
+			ID:                		stringMap["Id"],
+			LogEntry:          		stringMap["LogEntry"],
+			LogEntrySource:    		stringMap["LogEntrySource"],
+			LogEntryTimeStamp: 		stringMap["LogEntryTimeStamp"],
+			LogEntryTimeOfCommand: 	start.Format(time.RFC3339),
+			SourceSystem:      		stringMap["SourceSystem"],
+			Computer:          		Computer,
+			Image:             		stringMap["Image"],
+			Name:              		stringMap["Name"],
 		}
 
 		dataItems = append(dataItems, dataItem)
+		loggedTime, e := time.Parse(time.RFC3339, dataItem.LogEntryTimeStamp)
+		if e!= nil {
+			message := fmt.Sprintf("Error while converting LogEntryTimeStamp for telemetry purposes: %s", e.Error())
+			Log(message)
+			SendException(message)
+		} else {
+			ltncy := float64(start.Sub(loggedTime) / time.Millisecond)
+			if ltncy >= maxLatency {
+				maxLatency = ltncy
+				maxLatencyContainer = dataItem.Name + "=" + dataItem.ID
+			}
+		}
 	}
 
 	if len(dataItems) > 0 {
@@ -302,6 +321,12 @@ func PostDataHelper(tailPluginRecords []map[interface{}]interface{}) int {
 		ContainerLogTelemetryMutex.Lock()
 		FlushedRecordsCount += float64(numRecords)
 		FlushedRecordsTimeTaken += float64(elapsed / time.Millisecond)
+
+		if maxLatency >= AgentLogProcessingMaxLatencyMs {
+			AgentLogProcessingMaxLatencyMs = maxLatency
+			AgentLogProcessingMaxLatencyMsContainer = maxLatencyContainer
+		}
+
 		ContainerLogTelemetryMutex.Unlock()
 	}
 

source/code/go/src/plugins/telemetry.go

@@ -17,6 +17,10 @@ var (
 	FlushedRecordsCount float64
 	// FlushedRecordsTimeTaken indicates the cumulative time taken to flush the records for the current period
 	FlushedRecordsTimeTaken float64
+	// This is telemetry for how old/latent logs we are processing in milliseconds (max over a period of time)
+	AgentLogProcessingMaxLatencyMs float64
+	// This is telemetry for which container logs were latent (max over a period of time)
+	AgentLogProcessingMaxLatencyMsContainer string
 	// CommonProperties indicates the dimensions that are sent with every event/metric
 	CommonProperties map[string]string
 	// TelemetryClient is the client used to send the telemetry
@@ -35,6 +39,8 @@ const (
 	envAppInsightsAuth                  = "APPLICATIONINSIGHTS_AUTH"
 	metricNameAvgFlushRate              = "ContainerLogAvgRecordsFlushedPerSec"
 	metricNameAvgLogGenerationRate      = "ContainerLogsGeneratedPerSec"
+	metricNameAgentLogProcessingMaxLatencyMs = "ContainerLogsAgentSideLatencyMs"
+
 	defaultTelemetryPushIntervalSeconds = 300
 
 	eventNameContainerLogInit   = "ContainerLogPluginInitialized"
@@ -62,12 +68,19 @@ func SendContainerLogPluginMetrics(telemetryPushIntervalProperty string) {
 		logRate := FlushedRecordsCount / float64(elapsed/time.Second)
 		FlushedRecordsCount = 0.0
 		FlushedRecordsTimeTaken = 0.0
+		logLatencyMs := AgentLogProcessingMaxLatencyMs
+		logLatencyMsContainer := AgentLogProcessingMaxLatencyMsContainer
+		AgentLogProcessingMaxLatencyMs = 0
+		AgentLogProcessingMaxLatencyMsContainer = ""
 		ContainerLogTelemetryMutex.Unlock()
 
 		flushRateMetric := appinsights.NewMetricTelemetry(metricNameAvgFlushRate, flushRate)
 		TelemetryClient.Track(flushRateMetric)
 		logRateMetric := appinsights.NewMetricTelemetry(metricNameAvgLogGenerationRate, logRate)
 		TelemetryClient.Track(logRateMetric)
+		logLatencyMetric := appinsights.NewMetricTelemetry(metricNameAgentLogProcessingMaxLatencyMs, logLatencyMs)
+		logLatencyMetric.Properties["Container"] = logLatencyMsContainer
+		TelemetryClient.Track(logLatencyMetric)
 		start = time.Now()
 	}
 }

source/code/plugin/ApplicationInsightsUtility.rb

@@ -13,12 +13,13 @@ class ApplicationInsightsUtility
     @@Exception = 'ExceptionEvent'
     @@AcsClusterType = 'ACS'
     @@AksClusterType = 'AKS'
-    @@DaemonsetControllerType = 'DaemonSet'
     @OmsAdminFilePath = '/etc/opt/microsoft/omsagent/conf/omsadmin.conf'
     @@EnvAcsResourceName = 'ACS_RESOURCE_NAME'
     @@EnvAksRegion = 'AKS_REGION'
     @@EnvAgentVersion = 'AGENT_VERSION'
     @@EnvApplicationInsightsKey = 'APPLICATIONINSIGHTS_AUTH'
+    @@EnvControllerType = 'CONTROLLER_TYPE'
+
     @@CustomProperties = {}
     @@Tc = nil
     @@hostName = (OMS::Common.get_hostname)
@@ -54,12 +55,11 @@ def initializeUtility()
 		            @@CustomProperties["ClusterName"] = clusterName
 		            @@CustomProperties["Region"] = ENV[@@EnvAksRegion]
                 end
-                @@CustomProperties['ControllerType'] = @@DaemonsetControllerType
-                dockerInfo = DockerApiClient.dockerInfo
-                @@CustomProperties['DockerVersion'] = dockerInfo['Version']
-                @@CustomProperties['DockerApiVersion'] = dockerInfo['ApiVersion']
+
+                getDockerInfo()
                 @@CustomProperties['WorkspaceID'] = getWorkspaceId
                 @@CustomProperties['AgentVersion'] = ENV[@@EnvAgentVersion]
+                @@CustomProperties['ControllerType'] = ENV[@@EnvControllerType]
                 encodedAppInsightsKey = ENV[@@EnvApplicationInsightsKey]
                 if !encodedAppInsightsKey.nil?
                     decodedAppInsightsKey = Base64.decode64(encodedAppInsightsKey)
@@ -70,6 +70,14 @@ def initializeUtility()
             end
         end
 
+        def getDockerInfo() 
+            dockerInfo = DockerApiClient.dockerInfo
+            if (!dockerInfo.nil? && !dockerInfo.empty?)
+                @@CustomProperties['DockerVersion'] = dockerInfo['Version']
+                @@CustomProperties['DockerApiVersion'] = dockerInfo['ApiVersion']
+            end
+        end
+
         def sendHeartBeatEvent(pluginName)
             begin
                 eventName = pluginName + @@HeartBeat
@@ -83,7 +91,7 @@ def sendHeartBeatEvent(pluginName)
             end
         end
 
-        def sendCustomEvent(pluginName, properties)
+        def sendCustomMetric(pluginName, properties)
             begin
                 if !(@@Tc.nil?)
                     @@Tc.track_metric 'LastProcessedContainerInventoryCount', properties['ContainerCount'], 
@@ -93,14 +101,16 @@ def sendCustomEvent(pluginName, properties)
                     $log.info("AppInsights Container Count Telemetry sent successfully")
                 end
             rescue => errorStr
-                $log.warn("Exception in AppInsightsUtility: sendCustomEvent - error: #{errorStr}")
+                $log.warn("Exception in AppInsightsUtility: sendCustomMetric - error: #{errorStr}")
             end
         end
 
         def sendExceptionTelemetry(errorStr)
             begin
                 if @@CustomProperties.empty? || @@CustomProperties.nil?
-                    initializeUtility
+                    initializeUtility()
+                elsif @@CustomProperties['DockerVersion'].nil?
+                    getDockerInfo()
                 end
                 if !(@@Tc.nil?)
                     @@Tc.track_exception errorStr , :properties => @@CustomProperties
@@ -116,11 +126,13 @@ def sendExceptionTelemetry(errorStr)
         def sendTelemetry(pluginName, properties)
             begin
                 if @@CustomProperties.empty? || @@CustomProperties.nil?
-                    initializeUtility
+                    initializeUtility()
+                elsif @@CustomProperties['DockerVersion'].nil?
+                    getDockerInfo()
                 end
                 @@CustomProperties['Computer'] = properties['Computer']
                 sendHeartBeatEvent(pluginName)
-                sendCustomEvent(pluginName, properties)
+                sendCustomMetric(pluginName, properties)
             rescue => errorStr
                 $log.warn("Exception in AppInsightsUtility: sendTelemetry - error: #{errorStr}")
             end
@@ -134,7 +146,9 @@ def sendMetricTelemetry(metricName, metricValue, properties)
                     return
                 end
                 if @@CustomProperties.empty? || @@CustomProperties.nil?
-                    initializeUtility
+                    initializeUtility()
+                elsif @@CustomProperties['DockerVersion'].nil?
+                    getDockerInfo()
                 end
                 telemetryProps = {}
                 telemetryProps["Computer"] = @@hostName