You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficcontrol.apache.org by GitBox <gi...@apache.org> on 2022/03/04 23:37:50 UTC

[GitHub] [trafficcontrol] srijeet0406 opened a new pull request #6620: Adding access.log to Traffic Monitor

srijeet0406 opened a new pull request #6620:
URL: https://github.com/apache/trafficcontrol/pull/6620


   <!--
   Thank you for contributing! Please be sure to read our contribution guidelines: https://github.com/apache/trafficcontrol/blob/master/CONTRIBUTING.md
   If this closes or relates to an existing issue, please reference it using one of the following:
   
   Closes: #ISSUE
   Related: #ISSUE
   
   If this PR fixes a security vulnerability, DO NOT submit! Instead, contact
   the Apache Traffic Control Security Team at security@trafficcontrol.apache.org and follow the
   guidelines at https://apache.org/security regarding vulnerability disclosure.
   -->
   This PR is not related to any issue.
   
   <!-- **^ Add meaningful description above** --><hr/>
   
   ## Which Traffic Control components are affected by this PR?
   <!-- Please delete all components from this list that are NOT affected by this PR.
   Feel free to add the name of a tool or script that is affected but not on the list.
   -->
   - Traffic Monitor
   - CDN in a Box
   
   ## What is the best way to verify this PR?
   <!-- Please include here ALL the steps necessary to test your PR.
   If your PR has tests (and most should), provide the steps needed to run the tests.
   If not, please provide step-by-step instructions to test the PR manually and explain why your PR does not need tests. -->
   Run Traffic Monitor and hit the APIs exposed by TM. Make sure you see the appropriate logs in the file specified by your access log location.
   
   ## If this is a bugfix, which Traffic Control versions contained the bug?
   <!-- Delete this section if the PR is not a bugfix, or if the bug is only in the master branch.
   Examples:
   - 5.1.2
   - 5.1.3 (RC1)
    -->
   - master
   
   ## PR submission checklist
   - [ ] This PR has tests <!-- If not, please delete this text and explain why this PR does not need tests. -->
   - [ ] This PR has documentation <!-- If not, please delete this text and explain why this PR does not need documentation. -->
   - [x] This PR has a CHANGELOG.md entry <!-- A fix for a bug from an ATC release, an improvement, or a new feature should have a changelog entry. -->
   - [x] This PR **DOES NOT FIX A SERIOUS SECURITY VULNERABILITY** (see [the Apache Software Foundation's security guidelines](https://apache.org/security) for details)
   
   <!--
   Licensed to the Apache Software Foundation (ASF) under one
   or more contributor license agreements.  See the NOTICE file
   distributed with this work for additional information
   regarding copyright ownership.  The ASF licenses this file
   to you under the Apache License, Version 2.0 (the
   "License"); you may not use this file except in compliance
   with the License.  You may obtain a copy of the License at
   
       http://www.apache.org/licenses/LICENSE-2.0
   
   Unless required by applicable law or agreed to in writing,
   software distributed under the License is distributed on an
   "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
   KIND, either express or implied.  See the License for the
   specific language governing permissions and limitations
   under the License.
   -->
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficcontrol.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficcontrol] rawlinp merged pull request #6620: Adding access.log to Traffic Monitor

Posted by GitBox <gi...@apache.org>.
rawlinp merged pull request #6620:
URL: https://github.com/apache/trafficcontrol/pull/6620


   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficcontrol.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficcontrol] rawlinp commented on a change in pull request #6620: Adding access.log to Traffic Monitor

Posted by GitBox <gi...@apache.org>.
rawlinp commented on a change in pull request #6620:
URL: https://github.com/apache/trafficcontrol/pull/6620#discussion_r826407437



##########
File path: traffic_monitor/datareq/datareq.go
##########
@@ -286,24 +287,56 @@ func WrapAgeErr(errorCount threadsafe.Uint, f func() ([]byte, time.Time, error),
 	}
 }
 
+func accessLogTime(t time.Time) float64 {
+	return float64(t.UnixMilli()) / 1000.0
+}
+
+func accessLogStr(
+	timestamp time.Time, // prefix
+	remoteAddress string, // chi
+	reqMethod string, // cqhm
+	reqPath string, // url
+	reqRawQuery string,
+	statusCode int, // pssc
+	respSize int, // b
+	reqServeTimeMs int, // ttms
+	userAgent string, // uas
+) string {
+	return fmt.Sprintf("%.3f chi=%s cqhm=%s url=\"%s?%s\" pssc=%d b=%d ttms=%d uas=\"%s\"",
+		accessLogTime(timestamp),
+		remoteAddress,
+		reqMethod,
+		reqPath,
+		reqRawQuery,
+		statusCode,
+		respSize,
+		reqServeTimeMs,
+		userAgent)
+}
+
 // WrapUnpolledCheck wraps an http.HandlerFunc, returning ServiceUnavailable if all caches have't been polled; else, calling the wrapped func. Once all caches have been polled, we never return a 503 again, even if the CRConfig has been changed and new, unpolled caches exist. This is because, before those new caches existed in the CRConfig, they weren't being routed to, so it doesn't break anything to continue not routing to them until they're polled, while still serving polled caches as available. Whereas, on startup, if we were to return data with some caches unpolled, we would be telling clients that existing, potentially-available caches are unavailable, simply because we hadn't polled them yet.
 func wrapUnpolledCheck(unpolledCaches threadsafe.UnpolledCaches, errorCount threadsafe.Uint, f http.HandlerFunc) http.HandlerFunc {
+	start := time.Now()

Review comment:
       The `ttms` appears to be incorrect, and I _think_ it's because this line needs to be in the _returned_ function rather than _this_ function.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficcontrol.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficcontrol] srijeet0406 commented on a change in pull request #6620: Adding access.log to Traffic Monitor

Posted by GitBox <gi...@apache.org>.
srijeet0406 commented on a change in pull request #6620:
URL: https://github.com/apache/trafficcontrol/pull/6620#discussion_r826416062



##########
File path: traffic_monitor/datareq/datareq.go
##########
@@ -286,24 +287,56 @@ func WrapAgeErr(errorCount threadsafe.Uint, f func() ([]byte, time.Time, error),
 	}
 }
 
+func accessLogTime(t time.Time) float64 {
+	return float64(t.UnixMilli()) / 1000.0
+}
+
+func accessLogStr(
+	timestamp time.Time, // prefix
+	remoteAddress string, // chi
+	reqMethod string, // cqhm
+	reqPath string, // url
+	reqRawQuery string,
+	statusCode int, // pssc
+	respSize int, // b
+	reqServeTimeMs int, // ttms
+	userAgent string, // uas
+) string {
+	return fmt.Sprintf("%.3f chi=%s cqhm=%s url=\"%s?%s\" pssc=%d b=%d ttms=%d uas=\"%s\"",
+		accessLogTime(timestamp),
+		remoteAddress,
+		reqMethod,
+		reqPath,
+		reqRawQuery,
+		statusCode,
+		respSize,
+		reqServeTimeMs,
+		userAgent)
+}
+
 // WrapUnpolledCheck wraps an http.HandlerFunc, returning ServiceUnavailable if all caches have't been polled; else, calling the wrapped func. Once all caches have been polled, we never return a 503 again, even if the CRConfig has been changed and new, unpolled caches exist. This is because, before those new caches existed in the CRConfig, they weren't being routed to, so it doesn't break anything to continue not routing to them until they're polled, while still serving polled caches as available. Whereas, on startup, if we were to return data with some caches unpolled, we would be telling clients that existing, potentially-available caches are unavailable, simply because we hadn't polled them yet.
 func wrapUnpolledCheck(unpolledCaches threadsafe.UnpolledCaches, errorCount threadsafe.Uint, f http.HandlerFunc) http.HandlerFunc {
+	start := time.Now()

Review comment:
       Good catch! Fixed now.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficcontrol.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficcontrol] rawlinp commented on a change in pull request #6620: Adding access.log to Traffic Monitor

Posted by GitBox <gi...@apache.org>.
rawlinp commented on a change in pull request #6620:
URL: https://github.com/apache/trafficcontrol/pull/6620#discussion_r826133088



##########
File path: traffic_monitor/datareq/datareq.go
##########
@@ -286,24 +287,56 @@ func WrapAgeErr(errorCount threadsafe.Uint, f func() ([]byte, time.Time, error),
 	}
 }
 
+func accessLogTime(t time.Time) float64 {
+	return float64(t.Unix()) + (float64(t.Nanosecond()) / 1e9)

Review comment:
       Oops, I think I forgot to add a comment I had written here. Can this be simplified to this?
   ```
   float64(t.UnixMilli()) / 1000.0
   ```




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficcontrol.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficcontrol] rawlinp commented on a change in pull request #6620: Adding access.log to Traffic Monitor

Posted by GitBox <gi...@apache.org>.
rawlinp commented on a change in pull request #6620:
URL: https://github.com/apache/trafficcontrol/pull/6620#discussion_r824158150



##########
File path: traffic_monitor/build/traffic_monitor.logrotate
##########
@@ -34,3 +34,13 @@
         rotate 5
         copytruncate
 }
+
+/opt/traffic_monitor/var/log/access.log {
+        compress
+        maxage 30
+        missingok
+        nomail
+        size 10M
+        rotate 5
+        copytruncate
+}

Review comment:
       missing newline at end of file

##########
File path: traffic_monitor/config/config.go
##########
@@ -132,6 +135,17 @@ func (c Config) WarningLog() log.LogLocation { return log.LogLocation(c.LogLocat
 func (c Config) InfoLog() log.LogLocation    { return log.LogLocation(c.LogLocationInfo) }
 func (c Config) DebugLog() log.LogLocation   { return log.LogLocation(c.LogLocationDebug) }
 func (c Config) EventLog() log.LogLocation   { return log.LogLocation(c.LogLocationEvent) }
+func (c Config) AccessLog() log.LogLocation  { return log.LogLocation(c.LogLocationAccess) }
+
+func GetAccessLogWriters(cfg Config) (io.WriteCloser, error) {
+	accessLoc := cfg.AccessLog()
+
+	accessW, err := log.GetLogWriter(accessLoc)
+	if err != nil {
+		return nil, fmt.Errorf("getting log access writer %v: %v", accessLoc, err)
+	}
+	return accessW, nil
+}
 
 // DefaultConfig is the default configuration for the application, if no configuration file is given, or if a given config setting doesn't exist in the config file.
 var DefaultConfig = Config{

Review comment:
       Should we update `DefaultConfig` to set it to `LogLocationNull`?

##########
File path: traffic_monitor/config/config.go
##########
@@ -132,6 +135,17 @@ func (c Config) WarningLog() log.LogLocation { return log.LogLocation(c.LogLocat
 func (c Config) InfoLog() log.LogLocation    { return log.LogLocation(c.LogLocationInfo) }
 func (c Config) DebugLog() log.LogLocation   { return log.LogLocation(c.LogLocationDebug) }
 func (c Config) EventLog() log.LogLocation   { return log.LogLocation(c.LogLocationEvent) }
+func (c Config) AccessLog() log.LogLocation  { return log.LogLocation(c.LogLocationAccess) }
+
+func GetAccessLogWriters(cfg Config) (io.WriteCloser, error) {

Review comment:
       This being plural makes it seem like it returns a slice of writers rather than a single writer -- should we singularize it?

##########
File path: traffic_monitor/datareq/datareq.go
##########
@@ -286,24 +287,47 @@ func WrapAgeErr(errorCount threadsafe.Uint, f func() ([]byte, time.Time, error),
 	}
 }
 
+func accessLogTime(t time.Time) float64 {
+	return float64(t.Unix()) + (float64(t.Nanosecond()) / 1e9)
+}
+
+func accessLogStr(
+	timestamp time.Time, // prefix
+	remoteAddress string, // addr
+	reqMethod string, // method
+	reqPath string, // path
+	reqProto string, // proto
+	statusCode int, // statusCode
+	respSize int, // respSize
+	reqServeTimeMs int, // reqServeTimeMs
+	userAgent string, // uas
+) string {
+	return fmt.Sprintf("%.3f addr=%s method=%s path=%s proto=%s statusCode=%d respSize=%d reqServeTimeMs=%d uas=%s", accessLogTime(timestamp), remoteAddress, reqMethod, reqPath, reqProto, statusCode, respSize, reqServeTimeMs, userAgent)

Review comment:
       Since this line is really long, should we put each parameter on its own line?
   
   Also, I think it makes sense to mimic ATS logging fields here since that is what we do for other ATC components (TR at least):
   ```
   %.3f chi=%s cqhm=%s url=\"%s?%s\" cqhv=%s pssc=%d b=%d ttms=%d uas=\"<user agent>\"
   ```
   for the `url` field, notice I've quoted it and made it `%s?%s` which should consist of `r.URL.Path` and `r.URL.RawQuery` so that we have the full URL. Also, the uas field should be quoted as well.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficcontrol.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficcontrol] rawlinp commented on a change in pull request #6620: Adding access.log to Traffic Monitor

Posted by GitBox <gi...@apache.org>.
rawlinp commented on a change in pull request #6620:
URL: https://github.com/apache/trafficcontrol/pull/6620#discussion_r826422696



##########
File path: traffic_monitor/traffic_monitor.go
##########
@@ -68,6 +77,11 @@ func main() {
 		os.Exit(1)
 	}
 
+	if err := InitAccessCfg(cfg); err != nil {
+		fmt.Printf("Error starting service: failed to create access log writers: %v\n", err)

Review comment:
       nit: writers -> writer




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficcontrol.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficcontrol] rawlinp commented on pull request #6620: Adding access.log to Traffic Monitor

Posted by GitBox <gi...@apache.org>.
rawlinp commented on pull request #6620:
URL: https://github.com/apache/trafficcontrol/pull/6620#issuecomment-1067007249


   Looks like the TM integration tests found a nil pointer deref:
   ```
   2022/03/11 22:04:51 http: panic serving 127.0.0.1:35022: runtime error: invalid memory address or nil pointer dereference
   goroutine 107 [running]:
   net/http.(*conn).serve.func1()
   	/opt/hostedtoolcache/go/1.17.8/x64/src/net/http/server.go:1802 +0xb9
   panic({0x7be140, 0xb54880})
   	/opt/hostedtoolcache/go/1.17.8/x64/src/runtime/panic.go:1047 +0x266
   log.(*Logger).Output(0x0, 0x1, {0xc00002b3b0, 0x6b})
   	/opt/hostedtoolcache/go/1.17.8/x64/src/log/log.go:165 +0x89
   log.(*Logger).Println(0xc00002b340, {0xc000639920, 0xc8, 0x1d})
   	/opt/hostedtoolcache/go/1.17.8/x64/src/log/log.go:200 +0x45
   github.com/apache/trafficcontrol/lib/go-log.Accessln(...)
   	/home/runner/go/src/github.com/apache/trafficcontrol/lib/go-log/log.go:132
   github.com/apache/trafficcontrol/traffic_monitor/datareq.wrapUnpolledCheck.func1.1()
   	/home/runner/go/src/github.com/apache/trafficcontrol/traffic_monitor/datareq/datareq.go:325 +0x1b6
   github.com/apache/trafficcontrol/traffic_monitor/datareq.wrapUnpolledCheck.func1({0x8d4e88, 0xc0002f40e0}, 0xc000758800)
   	/home/runner/go/src/github.com/apache/trafficcontrol/traffic_monitor/datareq/datareq.go:340 +0x34b
   net/http.HandlerFunc.ServeHTTP(0x0, {0x8d4e88, 0xc0002f40e0}, 0x0)
   	/opt/hostedtoolcache/go/1.17.8/x64/src/net/http/server.go:2047 +0x2f
   net/http.(*ServeMux).ServeHTTP(0x0, {0x8d4e88, 0xc0002f40e0}, 0xc000758800)
   	/opt/hostedtoolcache/go/1.17.8/x64/src/net/http/server.go:2425 +0x149
   net/http.serverHandler.ServeHTTP({0xc00026b440}, {0x8d4e88, 0xc0002f40e0}, 0xc000758800)
   	/opt/hostedtoolcache/go/1.17.8/x64/src/net/http/server.go:2879 +0x43b
   net/http.(*conn).serve(0xc0002feaa0, {0x8d74c0, 0xc000303680})
   	/opt/hostedtoolcache/go/1.17.8/x64/src/net/http/server.go:1930 +0xb08
   created by net/http.(*Server).Serve
   	/opt/hostedtoolcache/go/1.17.8/x64/src/net/http/server.go:3034 +0x4e8
   ```


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficcontrol.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org