| 123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932 |
- /*
- * Copyright (c) 2015, Psiphon Inc.
- * All rights reserved.
- *
- * This program is free software: you can redistribute it and/or modify
- * it under the terms of the GNU General Public License as published by
- * the Free Software Foundation, either version 3 of the License, or
- * (at your option) any later version.
- *
- * This program is distributed in the hope that it will be useful,
- * but WITHOUT ANY WARRANTY; without even the implied warranty of
- * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
- * GNU General Public License for more details.
- *
- * You should have received a copy of the GNU General Public License
- * along with this program. If not, see <http://www.gnu.org/licenses/>.
- *
- */
- package psiphon
- import (
- "bytes"
- "encoding/json"
- "fmt"
- "io"
- "os"
- "sort"
- "strings"
- "sync"
- "sync/atomic"
- "time"
- "github.com/Psiphon-Labs/psiphon-tunnel-core/psiphon/common"
- )
- type noticeLogger struct {
- logDiagnostics int32
- mutex sync.Mutex
- writer io.Writer
- homepageFilename string
- homepageFile *os.File
- rotatingFilename string
- rotatingOlderFilename string
- rotatingFile *os.File
- rotatingFileSize int64
- rotatingCurrentFileSize int64
- rotatingSyncFrequency int
- rotatingCurrentNoticeCount int
- }
- var singletonNoticeLogger = noticeLogger{
- writer: os.Stderr,
- }
- // SetEmitDiagnosticNotices toggles whether diagnostic notices
- // are emitted. Diagnostic notices contain potentially sensitive
- // circumvention network information; only enable this in environments
- // where notices are handled securely (for example, don't include these
- // notices in log files which users could post to public forums).
- func SetEmitDiagnosticNotices(enable bool) {
- if enable {
- atomic.StoreInt32(&singletonNoticeLogger.logDiagnostics, 1)
- } else {
- atomic.StoreInt32(&singletonNoticeLogger.logDiagnostics, 0)
- }
- }
- // GetEmitDiagnoticNotices returns the current state
- // of emitting diagnostic notices.
- func GetEmitDiagnoticNotices() bool {
- return atomic.LoadInt32(&singletonNoticeLogger.logDiagnostics) == 1
- }
- // SetNoticeWriter sets a target writer to receive notices. By default,
- // notices are written to stderr. Notices are newline delimited.
- //
- // writer specifies an alternate io.Writer where notices are to be written.
- //
- // Notices are encoded in JSON. Here's an example:
- //
- // {"data":{"message":"shutdown operate tunnel"},"noticeType":"Info","showUser":false,"timestamp":"2006-01-02T15:04:05.999999999Z07:00"}
- //
- // All notices have the following fields:
- // - "noticeType": the type of notice, which indicates the meaning of the notice along with what's in the data payload.
- // - "data": additional structured data payload. For example, the "ListeningSocksProxyPort" notice type has a "port" integer
- // data in its payload.
- // - "showUser": whether the information should be displayed to the user. For example, this flag is set for "SocksProxyPortInUse"
- // as the user should be informed that their configured choice of listening port could not be used. Core clients should
- // anticipate that the core will add additional "showUser"=true notices in the future and emit at least the raw notice.
- // - "timestamp": UTC timezone, RFC3339Milli format timestamp for notice event
- //
- // See the Notice* functions for details on each notice meaning and payload.
- //
- func SetNoticeWriter(writer io.Writer) {
- singletonNoticeLogger.mutex.Lock()
- defer singletonNoticeLogger.mutex.Unlock()
- singletonNoticeLogger.writer = writer
- }
- // SetNoticeFiles configures files for notice writing.
- //
- // - When homepageFilename is not "", homepages are written to the specified file
- // and omitted from the writer. The file may be read after the Tunnels notice
- // with count of 1. The file should be opened read-only for reading.
- //
- // - When rotatingFilename is not "", all notices are are written to the specified
- // file. Diagnostic notices are omitted from the writer. The file is rotated
- // when its size exceeds rotatingFileSize. One rotated older file,
- // <rotatingFilename>.1, is retained. The files may be read at any time; and
- // should be opened read-only for reading. rotatingSyncFrequency specifies how
- // many notices are written before syncing the file.
- // If either rotatingFileSize or rotatingSyncFrequency are <= 0, default values
- // are used.
- //
- // - If an error occurs when writing to a file, an InternalError notice is emitted to
- // the writer.
- //
- // SetNoticeFiles closes open homepage or rotating files before applying the new
- // configuration.
- //
- func SetNoticeFiles(
- homepageFilename string,
- rotatingFilename string,
- rotatingFileSize int,
- rotatingSyncFrequency int) error {
- singletonNoticeLogger.mutex.Lock()
- defer singletonNoticeLogger.mutex.Unlock()
- if homepageFilename != "" {
- var err error
- if singletonNoticeLogger.homepageFile != nil {
- singletonNoticeLogger.homepageFile.Close()
- }
- singletonNoticeLogger.homepageFile, err = os.OpenFile(
- homepageFilename, os.O_CREATE|os.O_TRUNC|os.O_WRONLY, 0600)
- if err != nil {
- return common.ContextError(err)
- }
- }
- if rotatingFilename != "" {
- var err error
- if singletonNoticeLogger.rotatingFile != nil {
- singletonNoticeLogger.rotatingFile.Close()
- }
- singletonNoticeLogger.rotatingFile, err = os.OpenFile(
- rotatingFilename, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0600)
- if err != nil {
- return common.ContextError(err)
- }
- fileInfo, err := singletonNoticeLogger.rotatingFile.Stat()
- if err != nil {
- return common.ContextError(err)
- }
- if rotatingFileSize <= 0 {
- rotatingFileSize = 1 << 20
- }
- if rotatingSyncFrequency <= 0 {
- rotatingSyncFrequency = 100
- }
- singletonNoticeLogger.rotatingFilename = rotatingFilename
- singletonNoticeLogger.rotatingOlderFilename = rotatingFilename + ".1"
- singletonNoticeLogger.rotatingFileSize = int64(rotatingFileSize)
- singletonNoticeLogger.rotatingCurrentFileSize = fileInfo.Size()
- singletonNoticeLogger.rotatingSyncFrequency = rotatingSyncFrequency
- singletonNoticeLogger.rotatingCurrentNoticeCount = 0
- }
- return nil
- }
- const (
- noticeShowUser = 1
- noticeIsDiagnostic = 2
- noticeIsHomepage = 4
- noticeClearHomepages = 8
- noticeSyncHomepages = 16
- )
- // outputNotice encodes a notice in JSON and writes it to the output writer.
- func (nl *noticeLogger) outputNotice(noticeType string, noticeFlags uint32, args ...interface{}) {
- if (noticeFlags¬iceIsDiagnostic != 0) && atomic.LoadInt32(&nl.logDiagnostics) != 1 {
- return
- }
- obj := make(map[string]interface{})
- noticeData := make(map[string]interface{})
- obj["noticeType"] = noticeType
- obj["showUser"] = (noticeFlags¬iceShowUser != 0)
- obj["data"] = noticeData
- obj["timestamp"] = time.Now().UTC().Format(common.RFC3339Milli)
- for i := 0; i < len(args)-1; i += 2 {
- name, ok := args[i].(string)
- value := args[i+1]
- if ok {
- noticeData[name] = value
- }
- }
- encodedJson, err := json.Marshal(obj)
- var output []byte
- if err == nil {
- output = append(encodedJson, byte('\n'))
- } else {
- // Try to emit a properly formatted notice that the outer client can report.
- // One scenario where this is useful is if the preceding Marshal fails due to
- // bad data in the args. This has happened for a json.RawMessage field.
- output = makeNoticeInternalError(
- fmt.Sprintf("marshal notice failed: %s", common.ContextError(err)))
- }
- nl.mutex.Lock()
- defer nl.mutex.Unlock()
- skipWriter := false
- if nl.homepageFile != nil &&
- (noticeFlags¬iceIsHomepage != 0) {
- skipWriter = true
- err := nl.outputNoticeToHomepageFile(noticeFlags, output)
- if err != nil {
- output := makeNoticeInternalError(
- fmt.Sprintf("write homepage file failed: %s", err))
- nl.writer.Write(output)
- }
- }
- if nl.rotatingFile != nil {
- if !skipWriter {
- skipWriter = (noticeFlags¬iceIsDiagnostic != 0)
- }
- err := nl.outputNoticeToRotatingFile(output)
- if err != nil {
- output := makeNoticeInternalError(
- fmt.Sprintf("write rotating file failed: %s", err))
- nl.writer.Write(output)
- }
- }
- if !skipWriter {
- _, _ = nl.writer.Write(output)
- }
- }
- // NoticeInteralError is an error formatting or writing notices.
- // A NoticeInteralError handler must not call a Notice function.
- func makeNoticeInternalError(errorMessage string) []byte {
- // Format an Alert Notice (_without_ using json.Marshal, since that can fail)
- alertNoticeFormat := "{\"noticeType\":\"InternalError\",\"showUser\":false,\"timestamp\":\"%s\",\"data\":{\"message\":\"%s\"}}\n"
- return []byte(fmt.Sprintf(alertNoticeFormat, time.Now().UTC().Format(common.RFC3339Milli), errorMessage))
- }
- func (nl *noticeLogger) outputNoticeToHomepageFile(noticeFlags uint32, output []byte) error {
- if (noticeFlags & noticeClearHomepages) != 0 {
- err := nl.homepageFile.Truncate(0)
- if err != nil {
- return common.ContextError(err)
- }
- _, err = nl.homepageFile.Seek(0, 0)
- if err != nil {
- return common.ContextError(err)
- }
- }
- _, err := nl.homepageFile.Write(output)
- if err != nil {
- return common.ContextError(err)
- }
- if (noticeFlags & noticeSyncHomepages) != 0 {
- err = nl.homepageFile.Sync()
- if err != nil {
- return common.ContextError(err)
- }
- }
- return nil
- }
- func (nl *noticeLogger) outputNoticeToRotatingFile(output []byte) error {
- nl.rotatingCurrentFileSize += int64(len(output) + 1)
- if nl.rotatingCurrentFileSize >= nl.rotatingFileSize {
- // Note: all errors are fatal in order to preserve the
- // rotatingFileSize limit; e.g., no attempt is made to
- // continue writing to the file if it can't be rotated.
- err := nl.rotatingFile.Sync()
- if err != nil {
- return common.ContextError(err)
- }
- err = nl.rotatingFile.Close()
- if err != nil {
- return common.ContextError(err)
- }
- err = os.Rename(nl.rotatingFilename, nl.rotatingOlderFilename)
- if err != nil {
- return common.ContextError(err)
- }
- nl.rotatingFile, err = os.OpenFile(
- nl.rotatingFilename, os.O_CREATE|os.O_TRUNC|os.O_WRONLY, 0600)
- if err != nil {
- return common.ContextError(err)
- }
- nl.rotatingCurrentFileSize = 0
- }
- _, err := nl.rotatingFile.Write(output)
- if err != nil {
- return common.ContextError(err)
- }
- nl.rotatingCurrentNoticeCount += 1
- if nl.rotatingCurrentNoticeCount >= nl.rotatingSyncFrequency {
- nl.rotatingCurrentNoticeCount = 0
- err = nl.rotatingFile.Sync()
- if err != nil {
- return common.ContextError(err)
- }
- }
- return nil
- }
- // NoticeInfo is an informational message
- func NoticeInfo(format string, args ...interface{}) {
- singletonNoticeLogger.outputNotice(
- "Info", noticeIsDiagnostic,
- "message", fmt.Sprintf(format, args...))
- }
- // NoticeAlert is an alert message; typically a recoverable error condition
- func NoticeAlert(format string, args ...interface{}) {
- singletonNoticeLogger.outputNotice(
- "Alert", noticeIsDiagnostic,
- "message", fmt.Sprintf(format, args...))
- }
- // NoticeError is an error message; typically an unrecoverable error condition
- func NoticeError(format string, args ...interface{}) {
- singletonNoticeLogger.outputNotice(
- "Error", noticeIsDiagnostic,
- "message", fmt.Sprintf(format, args...))
- }
- // NoticeUserLog is a log message from the outer client user of tunnel-core
- func NoticeUserLog(message string) {
- singletonNoticeLogger.outputNotice(
- "UserLog", noticeIsDiagnostic,
- "message", message)
- }
- // NoticeCandidateServers is how many possible servers are available for the selected region and protocol
- func NoticeCandidateServers(region, protocol string, count int) {
- singletonNoticeLogger.outputNotice(
- "CandidateServers", noticeIsDiagnostic,
- "region", region,
- "protocol", protocol,
- "count", count)
- }
- // NoticeAvailableEgressRegions is what regions are available for egress from.
- // Consecutive reports of the same list of regions are suppressed.
- func NoticeAvailableEgressRegions(regions []string) {
- sortedRegions := append([]string(nil), regions...)
- sort.Strings(sortedRegions)
- repetitionMessage := strings.Join(sortedRegions, "")
- outputRepetitiveNotice(
- "AvailableEgressRegions", repetitionMessage, 0,
- "AvailableEgressRegions", 0, "regions", sortedRegions)
- }
- func noticeServerDialStats(noticeType, ipAddress, region, protocol string, tunnelDialStats *TunnelDialStats) {
- args := []interface{}{
- "ipAddress", ipAddress,
- "region", region,
- "protocol", protocol,
- }
- if tunnelDialStats.SelectedSSHClientVersion {
- args = append(args, "SSHClientVersion", tunnelDialStats.SSHClientVersion)
- }
- if tunnelDialStats.UpstreamProxyType != "" {
- args = append(args, "upstreamProxyType", tunnelDialStats.UpstreamProxyType)
- }
- if tunnelDialStats.UpstreamProxyCustomHeaderNames != nil {
- args = append(args, "upstreamProxyCustomHeaderNames", strings.Join(tunnelDialStats.UpstreamProxyCustomHeaderNames, ","))
- }
- if tunnelDialStats.MeekDialAddress != "" {
- args = append(args, "meekDialAddress", tunnelDialStats.MeekDialAddress)
- }
- if tunnelDialStats.MeekResolvedIPAddress != "" {
- args = append(args, "meekResolvedIPAddress", tunnelDialStats.MeekResolvedIPAddress)
- }
- if tunnelDialStats.MeekSNIServerName != "" {
- args = append(args, "meekSNIServerName", tunnelDialStats.MeekSNIServerName)
- }
- if tunnelDialStats.MeekHostHeader != "" {
- args = append(args, "meekHostHeader", tunnelDialStats.MeekHostHeader)
- }
- // MeekTransformedHostName is meaningful when meek is used, which is when MeekDialAddress != ""
- if tunnelDialStats.MeekDialAddress != "" {
- args = append(args, "meekTransformedHostName", tunnelDialStats.MeekTransformedHostName)
- }
- if tunnelDialStats.SelectedUserAgent {
- args = append(args, "userAgent", tunnelDialStats.UserAgent)
- }
- if tunnelDialStats.SelectedTLSProfile {
- args = append(args, "TLSProfile", tunnelDialStats.TLSProfile)
- }
- singletonNoticeLogger.outputNotice(
- noticeType, noticeIsDiagnostic,
- args...)
- }
- // NoticeConnectingServer reports parameters and details for a single connection attempt
- func NoticeConnectingServer(ipAddress, region, protocol string, tunnelDialStats *TunnelDialStats) {
- noticeServerDialStats(
- "ConnectingServer", ipAddress, region, protocol, tunnelDialStats)
- }
- // NoticeConnectedServer reports parameters and details for a single successful connection
- func NoticeConnectedServer(ipAddress, region, protocol string, tunnelDialStats *TunnelDialStats) {
- noticeServerDialStats(
- "ConnectedServer", ipAddress, region, protocol, tunnelDialStats)
- }
- // NoticeActiveTunnel is a successful connection that is used as an active tunnel for port forwarding
- func NoticeActiveTunnel(ipAddress, protocol string, isTCS bool) {
- singletonNoticeLogger.outputNotice(
- "ActiveTunnel", noticeIsDiagnostic,
- "ipAddress", ipAddress,
- "protocol", protocol,
- "isTCS", isTCS)
- }
- // NoticeSocksProxyPortInUse is a failure to use the configured LocalSocksProxyPort
- func NoticeSocksProxyPortInUse(port int) {
- singletonNoticeLogger.outputNotice(
- "SocksProxyPortInUse",
- noticeShowUser, "port", port)
- }
- // NoticeListeningSocksProxyPort is the selected port for the listening local SOCKS proxy
- func NoticeListeningSocksProxyPort(port int) {
- singletonNoticeLogger.outputNotice(
- "ListeningSocksProxyPort", 0,
- "port", port)
- }
- // NoticeHttpProxyPortInUse is a failure to use the configured LocalHttpProxyPort
- func NoticeHttpProxyPortInUse(port int) {
- singletonNoticeLogger.outputNotice(
- "HttpProxyPortInUse", noticeShowUser,
- "port", port)
- }
- // NoticeListeningHttpProxyPort is the selected port for the listening local HTTP proxy
- func NoticeListeningHttpProxyPort(port int) {
- singletonNoticeLogger.outputNotice(
- "ListeningHttpProxyPort", 0,
- "port", port)
- }
- // NoticeClientUpgradeAvailable is an available client upgrade, as per the handshake. The
- // client should download and install an upgrade.
- func NoticeClientUpgradeAvailable(version string) {
- singletonNoticeLogger.outputNotice(
- "ClientUpgradeAvailable", 0,
- "version", version)
- }
- // NoticeClientIsLatestVersion reports that an upgrade check was made and the client
- // is already the latest version. availableVersion is the version available for download,
- // if known.
- func NoticeClientIsLatestVersion(availableVersion string) {
- singletonNoticeLogger.outputNotice(
- "ClientIsLatestVersion", 0,
- "availableVersion", availableVersion)
- }
- // NoticeHomepages emits a series of NoticeHomepage, the sponsor homepages. The client
- // should display the sponsor's homepages.
- func NoticeHomepages(urls []string) {
- for i, url := range urls {
- noticeFlags := uint32(noticeIsHomepage)
- if i == 0 {
- noticeFlags |= noticeClearHomepages
- }
- if i == len(urls)-1 {
- noticeFlags |= noticeSyncHomepages
- }
- singletonNoticeLogger.outputNotice(
- "Homepage", noticeFlags,
- "url", url)
- }
- }
- // NoticeClientVerificationRequired indicates that client verification is required, as
- // indicated by the handshake. The client should submit a client verification payload.
- // Empty nonce is allowed, if ttlSeconds is 0 the client should not send verification
- // payload to the server. If resetCache is set the client must always perform a new
- // verification and update its cache
- func NoticeClientVerificationRequired(nonce string, ttlSeconds int, resetCache bool) {
- singletonNoticeLogger.outputNotice(
- "ClientVerificationRequired", 0,
- "nonce", nonce,
- "ttlSeconds", ttlSeconds,
- "resetCache", resetCache)
- }
- // NoticeClientRegion is the client's region, as determined by the server and
- // reported to the client in the handshake.
- func NoticeClientRegion(region string) {
- singletonNoticeLogger.outputNotice(
- "ClientRegion", 0,
- "region", region)
- }
- // NoticeTunnels is how many active tunnels are available. The client should use this to
- // determine connecting/unexpected disconnect state transitions. When count is 0, the core is
- // disconnected; when count > 1, the core is connected.
- func NoticeTunnels(count int) {
- singletonNoticeLogger.outputNotice(
- "Tunnels", 0,
- "count", count)
- }
- // NoticeSessionId is the session ID used across all tunnels established by the controller.
- func NoticeSessionId(sessionId string) {
- singletonNoticeLogger.outputNotice(
- "SessionId", noticeIsDiagnostic,
- "sessionId", sessionId)
- }
- func NoticeImpairedProtocolClassification(impairedProtocolClassification map[string]int) {
- singletonNoticeLogger.outputNotice(
- "ImpairedProtocolClassification", noticeIsDiagnostic,
- "classification", impairedProtocolClassification)
- }
- // NoticeUntunneled indicates than an address has been classified as untunneled and is being
- // accessed directly.
- //
- // Note: "address" should remain private; this notice should only be used for alerting
- // users, not for diagnostics logs.
- //
- func NoticeUntunneled(address string) {
- singletonNoticeLogger.outputNotice(
- "Untunneled", noticeShowUser,
- "address", address)
- }
- // NoticeSplitTunnelRegion reports that split tunnel is on for the given region.
- func NoticeSplitTunnelRegion(region string) {
- singletonNoticeLogger.outputNotice(
- "SplitTunnelRegion", noticeShowUser,
- "region", region)
- }
- // NoticeUpstreamProxyError reports an error when connecting to an upstream proxy. The
- // user may have input, for example, an incorrect address or incorrect credentials.
- func NoticeUpstreamProxyError(err error) {
- singletonNoticeLogger.outputNotice(
- "UpstreamProxyError", noticeShowUser,
- "message", err.Error())
- }
- // NoticeClientUpgradeDownloadedBytes reports client upgrade download progress.
- func NoticeClientUpgradeDownloadedBytes(bytes int64) {
- singletonNoticeLogger.outputNotice(
- "ClientUpgradeDownloadedBytes", noticeIsDiagnostic,
- "bytes", bytes)
- }
- // NoticeClientUpgradeDownloaded indicates that a client upgrade download
- // is complete and available at the destination specified.
- func NoticeClientUpgradeDownloaded(filename string) {
- singletonNoticeLogger.outputNotice(
- "ClientUpgradeDownloaded", 0,
- "filename", filename)
- }
- // NoticeBytesTransferred reports how many tunneled bytes have been
- // transferred since the last NoticeBytesTransferred, for the tunnel
- // to the server at ipAddress. This is not a diagnostic notice: the
- // user app has requested this notice with EmitBytesTransferred for
- // functionality such as traffic display; and this frequent notice
- // is not intended to be included with feedback.
- func NoticeBytesTransferred(ipAddress string, sent, received int64) {
- singletonNoticeLogger.outputNotice(
- "BytesTransferred", 0,
- "sent", sent,
- "received", received)
- }
- // NoticeTotalBytesTransferred reports how many tunneled bytes have been
- // transferred in total up to this point, for the tunnel to the server
- // at ipAddress. This is a diagnostic notice.
- func NoticeTotalBytesTransferred(ipAddress string, sent, received int64) {
- singletonNoticeLogger.outputNotice(
- "TotalBytesTransferred", noticeIsDiagnostic,
- "ipAddress", ipAddress,
- "sent", sent,
- "received", received)
- }
- // NoticeLocalProxyError reports a local proxy error message. Repetitive
- // errors for a given proxy type are suppressed.
- func NoticeLocalProxyError(proxyType string, err error) {
- // For repeats, only consider the base error message, which is
- // the root error that repeats (the full error often contains
- // different specific values, e.g., local port numbers, but
- // the same repeating root).
- // Assumes error format of common.ContextError.
- repetitionMessage := err.Error()
- index := strings.LastIndex(repetitionMessage, ": ")
- if index != -1 {
- repetitionMessage = repetitionMessage[index+2:]
- }
- outputRepetitiveNotice(
- "LocalProxyError"+proxyType, repetitionMessage, 1,
- "LocalProxyError", noticeIsDiagnostic,
- "message", err.Error())
- }
- // NoticeBuildInfo reports build version info.
- func NoticeBuildInfo() {
- singletonNoticeLogger.outputNotice(
- "BuildInfo", noticeIsDiagnostic,
- "buildInfo", common.GetBuildInfo())
- }
- // NoticeExiting indicates that tunnel-core is exiting imminently.
- func NoticeExiting() {
- singletonNoticeLogger.outputNotice(
- "Exiting", 0)
- }
- // NoticeRemoteServerListResourceDownloadedBytes reports remote server list download progress.
- func NoticeRemoteServerListResourceDownloadedBytes(url string, bytes int64) {
- singletonNoticeLogger.outputNotice(
- "RemoteServerListResourceDownloadedBytes", noticeIsDiagnostic,
- "url", url,
- "bytes", bytes)
- }
- // NoticeRemoteServerListResourceDownloaded indicates that a remote server list download
- // completed successfully.
- func NoticeRemoteServerListResourceDownloaded(url string) {
- singletonNoticeLogger.outputNotice(
- "RemoteServerListResourceDownloaded", noticeIsDiagnostic,
- "url", url)
- }
- func NoticeClientVerificationRequestCompleted(ipAddress string) {
- // TODO: remove "Notice" prefix
- singletonNoticeLogger.outputNotice(
- "NoticeClientVerificationRequestCompleted", noticeIsDiagnostic,
- "ipAddress", ipAddress)
- }
- // NoticeSLOKSeeded indicates that the SLOK with the specified ID was received from
- // the Psiphon server. The "duplicate" flags indicates whether the SLOK was previously known.
- func NoticeSLOKSeeded(slokID string, duplicate bool) {
- singletonNoticeLogger.outputNotice(
- "SLOKSeeded", noticeIsDiagnostic,
- "slokID", slokID,
- "duplicate", duplicate)
- }
- // NoticeServerTimestamp reports server side timestamp as seen in the handshake
- func NoticeServerTimestamp(timestamp string) {
- singletonNoticeLogger.outputNotice(
- "ServerTimestamp", 0,
- "timestamp", timestamp)
- }
- type repetitiveNoticeState struct {
- message string
- repeats int
- }
- var repetitiveNoticeMutex sync.Mutex
- var repetitiveNoticeStates = make(map[string]*repetitiveNoticeState)
- // outputRepetitiveNotice conditionally outputs a notice. Used for noticies which
- // often repeat in noisy bursts. For a repeat limit of N, the notice is emitted
- // with a "repeats" count on consecutive repeats up to the limit and then suppressed
- // until the repetitionMessage differs.
- func outputRepetitiveNotice(
- repetitionKey, repetitionMessage string, repeatLimit int,
- noticeType string, noticeFlags uint32, args ...interface{}) {
- repetitiveNoticeMutex.Lock()
- defer repetitiveNoticeMutex.Unlock()
- state, ok := repetitiveNoticeStates[repetitionKey]
- if !ok {
- state = new(repetitiveNoticeState)
- repetitiveNoticeStates[repetitionKey] = state
- }
- emit := true
- if repetitionMessage != state.message {
- state.message = repetitionMessage
- state.repeats = 0
- } else {
- state.repeats += 1
- if state.repeats > repeatLimit {
- emit = false
- }
- }
- if emit {
- if state.repeats > 0 {
- args = append(args, "repeats", state.repeats)
- }
- singletonNoticeLogger.outputNotice(
- noticeType, noticeFlags,
- args...)
- }
- }
- type noticeObject struct {
- NoticeType string `json:"noticeType"`
- Data json.RawMessage `json:"data"`
- Timestamp string `json:"timestamp"`
- }
- // GetNotice receives a JSON encoded object and attempts to parse it as a Notice.
- // The type is returned as a string and the payload as a generic map.
- func GetNotice(notice []byte) (
- noticeType string, payload map[string]interface{}, err error) {
- var object noticeObject
- err = json.Unmarshal(notice, &object)
- if err != nil {
- return "", nil, err
- }
- var objectPayload interface{}
- err = json.Unmarshal(object.Data, &objectPayload)
- if err != nil {
- return "", nil, err
- }
- return object.NoticeType, objectPayload.(map[string]interface{}), nil
- }
- // NoticeReceiver consumes a notice input stream and invokes a callback function
- // for each discrete JSON notice object byte sequence.
- type NoticeReceiver struct {
- mutex sync.Mutex
- buffer []byte
- callback func([]byte)
- }
- // NewNoticeReceiver initializes a new NoticeReceiver
- func NewNoticeReceiver(callback func([]byte)) *NoticeReceiver {
- return &NoticeReceiver{callback: callback}
- }
- // Write implements io.Writer.
- func (receiver *NoticeReceiver) Write(p []byte) (n int, err error) {
- receiver.mutex.Lock()
- defer receiver.mutex.Unlock()
- receiver.buffer = append(receiver.buffer, p...)
- index := bytes.Index(receiver.buffer, []byte("\n"))
- if index == -1 {
- return len(p), nil
- }
- notice := receiver.buffer[:index]
- receiver.callback(notice)
- if index == len(receiver.buffer)-1 {
- receiver.buffer = receiver.buffer[0:0]
- } else {
- receiver.buffer = receiver.buffer[index+1:]
- }
- return len(p), nil
- }
- // NewNoticeConsoleRewriter consumes JSON-format notice input and parses each
- // notice and rewrites in a more human-readable format more suitable for
- // console output. The data payload field is left as JSON.
- func NewNoticeConsoleRewriter(writer io.Writer) *NoticeReceiver {
- return NewNoticeReceiver(func(notice []byte) {
- var object noticeObject
- _ = json.Unmarshal(notice, &object)
- fmt.Fprintf(
- writer,
- "%s %s %s\n",
- object.Timestamp,
- object.NoticeType,
- string(object.Data))
- })
- }
- // NoticeWriter implements io.Writer and emits the contents of Write() calls
- // as Notices. This is to transform logger messages, if they can be redirected
- // to an io.Writer, to notices.
- type NoticeWriter struct {
- noticeType string
- }
- // NewNoticeWriter initializes a new NoticeWriter
- func NewNoticeWriter(noticeType string) *NoticeWriter {
- return &NoticeWriter{noticeType: noticeType}
- }
- // Write implements io.Writer.
- func (writer *NoticeWriter) Write(p []byte) (n int, err error) {
- singletonNoticeLogger.outputNotice(
- writer.noticeType, noticeIsDiagnostic,
- "message", string(p))
- return len(p), nil
- }
- // NoticeCommonLogger maps the common.Logger interface to the notice facility.
- // This is used to make the notice facility available to other packages that
- // don't import the "psiphon" package.
- func NoticeCommonLogger() common.Logger {
- return &commonLogger{}
- }
- type commonLogger struct {
- }
- func (logger *commonLogger) WithContext() common.LogContext {
- return &commonLogContext{
- context: common.GetParentContext(),
- }
- }
- func (logger *commonLogger) WithContextFields(fields common.LogFields) common.LogContext {
- return &commonLogContext{
- context: common.GetParentContext(),
- fields: fields,
- }
- }
- func (logger *commonLogger) LogMetric(metric string, fields common.LogFields) {
- singletonNoticeLogger.outputNotice(
- metric, noticeIsDiagnostic,
- listCommonFields(fields)...)
- }
- func listCommonFields(fields common.LogFields) []interface{} {
- fieldList := make([]interface{}, 0)
- for name, value := range fields {
- var formattedValue string
- if err, ok := value.(error); ok {
- formattedValue = err.Error()
- } else {
- formattedValue = fmt.Sprintf("%#v", value)
- }
- fieldList = append(fieldList, name, formattedValue)
- }
- return fieldList
- }
- type commonLogContext struct {
- context string
- fields common.LogFields
- }
- func (context *commonLogContext) outputNotice(
- noticeType string, args ...interface{}) {
- singletonNoticeLogger.outputNotice(
- noticeType, noticeIsDiagnostic,
- append(
- []interface{}{
- "message", fmt.Sprint(args...),
- "context", context.context},
- listCommonFields(context.fields)...)...)
- }
- func (context *commonLogContext) Debug(args ...interface{}) {
- // Ignored.
- }
- func (context *commonLogContext) Info(args ...interface{}) {
- context.outputNotice("Info", args)
- }
- func (context *commonLogContext) Warning(args ...interface{}) {
- context.outputNotice("Alert", args)
- }
- func (context *commonLogContext) Error(args ...interface{}) {
- context.outputNotice("Error", args)
- }
|