diff --git a/README.md b/README.md index af73f1b1..f0522842 100644 --- a/README.md +++ b/README.md @@ -57,11 +57,8 @@ Run the following command (check help string for more details): ``` ### Fetching logs -Run the following command (check help string for more details): - -```shell -./vse-sync-collection-tools logs --kubeconfig="${KUBECONFIG}" -``` +The log subcommand has been removed. Instead we have implimented at collector which is enabled by default. +If possible you should use a log aggregator. You can control the collectors running using the `--collector` flag. ## Running tests diff --git a/doc/implementing_a_collector.md b/doc/implementing_a_collector.md index c148431d..a4944059 100644 --- a/doc/implementing_a_collector.md +++ b/doc/implementing_a_collector.md @@ -145,6 +145,6 @@ func NewAnnouncementCollector(constuctor *CollectionConstuctor) (Collector, erro func init(){ // We'll make this a required collector - RegisterCollector(AnnouncementCollectorName, NewAnnouncementCollector, true) + RegisterCollector(AnnouncementCollectorName, NewAnnouncementCollector, required) } ``` diff --git a/pkg/clients/clientset.go b/pkg/clients/clientset.go index da5feb9a..275d81d7 100644 --- a/pkg/clients/clientset.go +++ b/pkg/clients/clientset.go @@ -18,12 +18,13 @@ import ( // A Clientset contains clients for the different k8s API groups in one place type Clientset struct { - RestConfig *rest.Config - DynamicClient dynamic.Interface - OcpClient ocpconfig.Interface - K8sClient kubernetes.Interface - K8sRestClient rest.Interface - ready bool + RestConfig *rest.Config + DynamicClient dynamic.Interface + OcpClient ocpconfig.Interface + K8sClient kubernetes.Interface + K8sRestClient rest.Interface + KubeConfigPaths []string + ready bool } var clientset = Clientset{} @@ -51,6 +52,7 @@ func GetClientset(kubeconfigPaths ...string) (*Clientset, error) { // newClientset will initialise the singleton clientset using provided kubeconfigPath func newClientset(kubeconfigPaths ...string) (*Clientset, error) { log.Infof("creating new Clientset from %v", kubeconfigPaths) + clientset.KubeConfigPaths = kubeconfigPaths loadingRules := clientcmd.NewDefaultClientConfigLoadingRules() loadingRules.Precedence = kubeconfigPaths // This means it will not load the value from $KUBECONFIG diff --git a/pkg/clients/exec_command.go b/pkg/clients/exec_command.go index eb5f8028..cfbd96ad 100644 --- a/pkg/clients/exec_command.go +++ b/pkg/clients/exec_command.go @@ -27,7 +27,7 @@ type ContainerContext struct { podNamePrefix string } -func (clientsholder *Clientset) findPodNameFromPrefix(namespace, prefix string) (string, error) { +func (clientsholder *Clientset) FindPodNameFromPrefix(namespace, prefix string) (string, error) { podList, err := clientsholder.K8sClient.CoreV1().Pods(namespace).List(context.TODO(), metav1.ListOptions{}) if err != nil { return "", fmt.Errorf("failed to getting pod list: %w", err) @@ -53,7 +53,7 @@ func (clientsholder *Clientset) findPodNameFromPrefix(namespace, prefix string) } func (c *ContainerContext) Refresh() error { - newPodname, err := c.clientset.findPodNameFromPrefix(c.namespace, c.podNamePrefix) + newPodname, err := c.clientset.FindPodNameFromPrefix(c.namespace, c.podNamePrefix) if err != nil { return err } @@ -65,7 +65,7 @@ func NewContainerContext( clientset *Clientset, namespace, podNamePrefix, containerName string, ) (ContainerContext, error) { - podName, err := clientset.findPodNameFromPrefix(namespace, podNamePrefix) + podName, err := clientset.FindPodNameFromPrefix(namespace, podNamePrefix) if err != nil { return ContainerContext{}, err } diff --git a/pkg/cmd/collect.go b/pkg/cmd/collect.go index b78d6328..32f6242c 100644 --- a/pkg/cmd/collect.go +++ b/pkg/cmd/collect.go @@ -3,21 +3,30 @@ package cmd import ( + "errors" "fmt" + "os" + "os/user" + "path/filepath" "strings" "time" log "github.com/sirupsen/logrus" "github.com/spf13/cobra" + "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/collectors" "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/runner" "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/utils" ) const ( - defaultDuration string = "1000s" - defaultPollInterval int = 1 - defaultDevInfoInterval int = 60 + defaultDuration string = "1000s" + defaultPollInterval int = 1 + defaultDevInfoInterval int = 60 + defaultIncludeLogTimestamps bool = false + defaultTempDir string = "." + defaultKeepDebugFiles bool = false + tempdirPerm = 0755 ) var ( @@ -25,6 +34,10 @@ var ( pollInterval int devInfoAnnouceInterval int collectorNames []string + logsOutputFile string + includeLogTimestamps bool + tempDir string + keepDebugFiles bool ) // collectCmd represents the collect command @@ -41,6 +54,30 @@ var collectCmd = &cobra.Command{ } utils.IfErrorExitOrPanic(err) + for _, c := range collectorNames { + if c == collectors.LogsCollectorName && logsOutputFile == "" { + utils.IfErrorExitOrPanic(utils.NewMissingInputError( + errors.New("if Logs collector is selected you must also provide a log output file")), + ) + } + } + + if strings.Contains(tempDir, "~") { + usr, err := user.Current() + if err != nil { + log.Fatal("Failed to fetch current user so could not resolve tempdir") + } + if tempDir == "~" { + tempDir = usr.HomeDir + } else if strings.HasPrefix(tempDir, "~/") { + tempDir = filepath.Join(usr.HomeDir, tempDir[2:]) + } + } + + if err := os.MkdirAll(tempDir, tempdirPerm); err != nil { + log.Fatal(err) + } + collectionRunner.Run( kubeConfig, outputFile, @@ -49,6 +86,10 @@ var collectCmd = &cobra.Command{ devInfoAnnouceInterval, ptpInterface, useAnalyserJSON, + logsOutputFile, + includeLogTimestamps, + tempDir, + keepDebugFiles, ) }, } @@ -99,4 +140,19 @@ func init() { //nolint:funlen // Allow this to get a little long strings.Join(runner.OptionalCollectorNames, ", "), ), ) + + collectCmd.Flags().StringVarP( + &logsOutputFile, + "logs-output", "l", "", + "Path to the logs output file. This is required when using the logs collector", + ) + collectCmd.Flags().BoolVar( + &includeLogTimestamps, + "log-timestamps", defaultIncludeLogTimestamps, + "Specifies if collected logs should include timestamps or not. (default is false)", + ) + + collectCmd.Flags().StringVarP(&tempDir, "tempdir", "t", defaultTempDir, + "Directory for storing temp/debug files. Must exist.") + collectCmd.Flags().BoolVar(&keepDebugFiles, "keep", defaultKeepDebugFiles, "Keep debug files") } diff --git a/pkg/cmd/logs.go b/pkg/cmd/logs.go deleted file mode 100644 index 7e1733c4..00000000 --- a/pkg/cmd/logs.go +++ /dev/null @@ -1,44 +0,0 @@ -// SPDX-License-Identifier: GPL-2.0-or-later - -package cmd - -import ( - "github.com/spf13/cobra" - - "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/grablogs" -) - -var ( - outputDirPath string - logWindow string - - // logsCmd represents the logs command - logsCmd = &cobra.Command{ - Use: "logs", - Short: "collect container logs", - Long: `collect container logs`, - Run: func(cmd *cobra.Command, args []string) { - grablogs.GrabLogs(kubeConfig, logWindow, outputDirPath) - }, - } -) - -func init() { - rootCmd.AddCommand(logsCmd) - AddKubeconfigFlag(logsCmd) - - logsCmd.PersistentFlags().StringVarP( - &outputDirPath, - "output-dir", - "o", - ".", - "Optional. Specify the output directory. Target must exist. Defaults to working directory.", - ) - - logsCmd.PersistentFlags().StringVar( - &logWindow, - "since", - "", - "Optional. Only get logs newer than a relative duration like 5s, 2m, or 3h. Defaults to all logs if omitted.", - ) -} diff --git a/pkg/collectors/collector.go b/pkg/collectors/collector.go index fa42d20c..cf88bf9f 100644 --- a/pkg/collectors/collector.go +++ b/pkg/collectors/collector.go @@ -23,8 +23,12 @@ type CollectionConstructor struct { ErroredPolls chan PollResult PTPInterface string Msg string + LogsOutputFile string + TempDir string PollInterval int DevInfoAnnouceInterval int + IncludeLogTimestamps bool + KeepDebugFiles bool } type PollResult struct { diff --git a/pkg/collectors/dev_info_collector.go b/pkg/collectors/dev_info_collector.go index acd03cb1..547785aa 100644 --- a/pkg/collectors/dev_info_collector.go +++ b/pkg/collectors/dev_info_collector.go @@ -204,5 +204,5 @@ func NewDevInfoCollector(constructor *CollectionConstructor) (Collector, error) } func init() { - RegisterCollector(DevInfoCollectorName, NewDevInfoCollector, true) + RegisterCollector(DevInfoCollectorName, NewDevInfoCollector, required) } diff --git a/pkg/collectors/dpll_collector.go b/pkg/collectors/dpll_collector.go index aec2775f..12c6c25a 100644 --- a/pkg/collectors/dpll_collector.go +++ b/pkg/collectors/dpll_collector.go @@ -108,5 +108,5 @@ func NewDPLLCollector(constructor *CollectionConstructor) (Collector, error) { } func init() { - RegisterCollector(DPLLCollectorName, NewDPLLCollector, false) + RegisterCollector(DPLLCollectorName, NewDPLLCollector, optional) } diff --git a/pkg/collectors/gps_ubx_collector.go b/pkg/collectors/gps_ubx_collector.go index 551bb81a..73bbc72b 100644 --- a/pkg/collectors/gps_ubx_collector.go +++ b/pkg/collectors/gps_ubx_collector.go @@ -94,5 +94,5 @@ func NewGPSCollector(constructor *CollectionConstructor) (Collector, error) { } func init() { - RegisterCollector(GPSCollectorName, NewGPSCollector, false) + RegisterCollector(GPSCollectorName, NewGPSCollector, optional) } diff --git a/pkg/collectors/log_follower.go b/pkg/collectors/log_follower.go new file mode 100644 index 00000000..3fc9c0d0 --- /dev/null +++ b/pkg/collectors/log_follower.go @@ -0,0 +1,298 @@ +// SPDX-License-Identifier: GPL-2.0-or-later + +package collectors + +import ( + "bufio" + "context" + "fmt" + "io" + "os" + "strings" + "sync" + "time" + "unicode" + + log "github.com/sirupsen/logrus" + v1 "k8s.io/api/core/v1" + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + + "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/clients" + "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/collectors/contexts" + "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/loglines" + "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/utils" +) + +const ( + lineSliceChanLength = 100 + lineChanLength = 1000 + lineDelim = '\n' + streamingBufferSize = 2000 + logPollInterval = 2 + logFilePermissions = 0666 + keepGenerations = 5 +) + +var ( + followDuration = logPollInterval * time.Second + followTimeout = 30 * followDuration +) + +// LogsCollector collects logs from repeated calls to the kubeapi with overlapping query times, +// the lines are then fed into a channel, in another goroutine they are de-duplicated and written to an output file. +// +// Overlap: +// cmd followDuration +// |---------------| +// since cmd followDuration +// |---------------|---------------| +// .............. since cmd followDuration +// .............. |---------------|---------------| +// +// This was done because oc logs and the kubeapi endpoint which it uses does not look back +// over a log rotation event, nor does it continue to follow. +// +// Log aggregators would be preferred over this method however this requires extra infra +// which might not be present in the environment. +type LogsCollector struct { + generations loglines.Generations + writeQuit chan os.Signal + lines chan *loglines.ProcessedLine + slices chan *loglines.LineSlice + client *clients.Clientset + sliceQuit chan os.Signal + logsOutputFileName string + lastPoll loglines.GenerationalLockedTime + wg sync.WaitGroup + pollInterval int + withTimeStamps bool + running bool + pruned bool +} + +const ( + LogsCollectorName = "Logs" + LogsInfo = "log-line" +) + +func (logs *LogsCollector) GetPollInterval() int { + return logs.pollInterval +} + +func (logs *LogsCollector) IsAnnouncer() bool { + return false +} + +func (logs *LogsCollector) SetLastPoll(pollTime time.Time) { + logs.lastPoll.Update(pollTime) +} + +// Start sets up the collector so it is ready to be polled +func (logs *LogsCollector) Start() error { + go logs.processSlices() + go logs.writeToLogFile() + logs.generations.Dumper.Start() + logs.running = true + return nil +} + +func (logs *LogsCollector) writeLine(line *loglines.ProcessedLine, writer io.StringWriter) { + var err error + if logs.withTimeStamps { + _, err = writer.WriteString(line.Full + "\n") + } else { + _, err = writer.WriteString(line.Content + "\n") + } + if err != nil { + log.Error("failed to write log output to file") + } +} + +//nolint:cyclop // allow this to be a little complicated +func (logs *LogsCollector) processSlices() { + logs.wg.Add(1) + defer logs.wg.Done() + for { + select { + case sig := <-logs.sliceQuit: + log.Debug("Clearing slices") + for len(logs.slices) > 0 { + lineSlice := <-logs.slices + logs.generations.Add(lineSlice) + } + log.Debug("Flushing remaining generations") + deduplicated := logs.generations.FlushAll() + for _, line := range deduplicated.Lines { + logs.lines <- line + } + log.Debug("Sending Signal to writer") + logs.writeQuit <- sig + return + case lineSlice := <-logs.slices: + logs.generations.Add(lineSlice) + default: + if logs.generations.ShouldFlush() { + deduplicated := logs.generations.Flush() + for _, line := range deduplicated.Lines { + logs.lines <- line + } + } + time.Sleep(time.Nanosecond) + } + } +} + +func (logs *LogsCollector) writeToLogFile() { + logs.wg.Add(1) + defer logs.wg.Done() + + fileHandle, err := os.OpenFile(logs.logsOutputFileName, os.O_CREATE|os.O_WRONLY, logFilePermissions) + utils.IfErrorExitOrPanic(err) + defer fileHandle.Close() + for { + select { + case <-logs.writeQuit: + // Consume the rest of the lines so we don't miss lines + for len(logs.lines) > 0 { + line := <-logs.lines + logs.writeLine(line, fileHandle) + } + return + case line := <-logs.lines: + logs.writeLine(line, fileHandle) + default: + time.Sleep(time.Nanosecond) + } + } +} + +func processLine(line string) (*loglines.ProcessedLine, error) { + splitLine := strings.SplitN(line, " ", 2) //nolint:gomnd // moving this to a var would make the code less clear + if len(splitLine) < 2 { //nolint:gomnd // moving this to a var would make the code less clear + return nil, fmt.Errorf("failed to split line %s", line) + } + timestampPart := splitLine[0] + lineContent := splitLine[1] + timestamp, err := time.Parse(time.RFC3339, timestampPart) + if err != nil { + // This is not a value line something went wrong + return nil, fmt.Errorf("failed to process timestamp from line: '%s'", line) + } + processed := &loglines.ProcessedLine{ + Timestamp: timestamp, + Content: strings.TrimRightFunc(lineContent, unicode.IsSpace), + Full: strings.TrimRightFunc(line, unicode.IsSpace), + } + return processed, nil +} + +//nolint:funlen // allow long function +func processStream(stream io.ReadCloser, expectedEndtime time.Time) ([]*loglines.ProcessedLine, error) { + scanner := bufio.NewScanner(stream) + segment := make([]*loglines.ProcessedLine, 0) + for scanner.Scan() { + if err := scanner.Err(); err != nil { + return segment, fmt.Errorf("error while reading logs stream %w", err) + } + pline, err := processLine(scanner.Text()) + if err != nil { + log.Warning("failed to process line: ", err) + continue + } + segment = append(segment, pline) + if expectedEndtime.Sub(pline.Timestamp) < 0 { + // Were past our expected end time lets finish there + break + } + } + return segment, nil +} + +func (logs *LogsCollector) poll() error { + podName, err := logs.client.FindPodNameFromPrefix(contexts.PTPNamespace, contexts.PTPPodNamePrefix) + if err != nil { + return fmt.Errorf("failed to poll: %w", err) + } + podLogOptions := v1.PodLogOptions{ + SinceTime: &metav1.Time{Time: logs.lastPoll.Time()}, + Container: contexts.PTPContainer, + Follow: true, + Previous: false, + Timestamps: true, + } + podLogRequest := logs.client.K8sClient.CoreV1(). + Pods(contexts.PTPNamespace). + GetLogs(podName, &podLogOptions). + Timeout(followTimeout) + stream, err := podLogRequest.Stream(context.TODO()) + if err != nil { + return fmt.Errorf("failed to poll when r: %w", err) + } + defer stream.Close() + + start := time.Now() + generation := logs.lastPoll.Generation() + lines, err := processStream(stream, time.Now().Add(followDuration)) + if err != nil { + return err + } + if len(lines) > 0 { + lineSlice := loglines.MakeSliceFromLines(lines, generation) + logs.slices <- lineSlice + logs.SetLastPoll(start) + } + return nil +} + +// Poll collects log lines +func (logs *LogsCollector) Poll(resultsChan chan PollResult, wg *utils.WaitGroupCount) { + defer func() { + wg.Done() + }() + errorsToReturn := make([]error, 0) + err := logs.poll() + if err != nil { + errorsToReturn = append(errorsToReturn, err) + } + resultsChan <- PollResult{ + CollectorName: LogsCollectorName, + Errors: errorsToReturn, + } +} + +// CleanUp stops a running collector +func (logs *LogsCollector) CleanUp() error { + logs.running = false + logs.sliceQuit <- os.Kill + log.Debug("waiting for logs to complete") + logs.wg.Wait() + logs.generations.Dumper.Stop() + return nil +} + +// Returns a new LogsCollector from the CollectionConstuctor Factory +func NewLogsCollector(constructor *CollectionConstructor) (Collector, error) { + collector := LogsCollector{ + running: false, + client: constructor.Clientset, + sliceQuit: make(chan os.Signal), + writeQuit: make(chan os.Signal), + pollInterval: logPollInterval, + pruned: true, + slices: make(chan *loglines.LineSlice, lineSliceChanLength), + lines: make(chan *loglines.ProcessedLine, lineChanLength), + lastPoll: loglines.NewGenerationalLockedTime(time.Now().Add(-time.Second)), // Stop initial since seconds from being 0 as its invalid + withTimeStamps: constructor.IncludeLogTimestamps, + logsOutputFileName: constructor.LogsOutputFile, + generations: loglines.Generations{ + Store: make(map[uint32][]*loglines.LineSlice), + Dumper: loglines.NewGenerationDumper(constructor.TempDir, constructor.KeepDebugFiles), + }, + } + return &collector, nil +} + +func init() { + // Make log opt in as in may lose some data. + RegisterCollector(LogsCollectorName, NewLogsCollector, optional) +} diff --git a/pkg/collectors/pmc_collector.go b/pkg/collectors/pmc_collector.go index ef1e9c53..2f4c3f40 100644 --- a/pkg/collectors/pmc_collector.go +++ b/pkg/collectors/pmc_collector.go @@ -92,5 +92,5 @@ func NewPMCCollector(constructor *CollectionConstructor) (Collector, error) { } func init() { - RegisterCollector(PMCCollectorName, NewPMCCollector, false) + RegisterCollector(PMCCollectorName, NewPMCCollector, optional) } diff --git a/pkg/collectors/registry.go b/pkg/collectors/registry.go index d1d18195..bef2adc8 100644 --- a/pkg/collectors/registry.go +++ b/pkg/collectors/registry.go @@ -4,9 +4,16 @@ package collectors import ( "fmt" + "log" ) type collectonBuilderFunc func(*CollectionConstructor) (Collector, error) +type collectorInclusionType int + +const ( + required collectorInclusionType = iota + optional +) type CollectorRegistry struct { registry map[string]collectonBuilderFunc @@ -23,13 +30,16 @@ func GetRegistry() *CollectorRegistry { func (reg *CollectorRegistry) register( collectorName string, builderFunc collectonBuilderFunc, - reqiuired bool, + inclusionType collectorInclusionType, ) { reg.registry[collectorName] = builderFunc - if reqiuired { + switch inclusionType { + case required: reg.required = append(reg.required, collectorName) - } else { + case optional: reg.optional = append(reg.optional, collectorName) + default: + log.Panic("Incorrect collector inclusion type") } } @@ -49,7 +59,7 @@ func (reg *CollectorRegistry) GetOptionalNames() []string { return reg.optional } -func RegisterCollector(collectorName string, builderFunc collectonBuilderFunc, required bool) { +func RegisterCollector(collectorName string, builderFunc collectonBuilderFunc, inclusionType collectorInclusionType) { if registry == nil { registry = &CollectorRegistry{ registry: make(map[string]collectonBuilderFunc, 0), @@ -57,5 +67,5 @@ func RegisterCollector(collectorName string, builderFunc collectonBuilderFunc, r optional: make([]string, 0), } } - registry.register(collectorName, builderFunc, required) + registry.register(collectorName, builderFunc, inclusionType) } diff --git a/pkg/grablogs/grab_logs.go b/pkg/grablogs/grab_logs.go deleted file mode 100644 index 2d2ec54a..00000000 --- a/pkg/grablogs/grab_logs.go +++ /dev/null @@ -1,66 +0,0 @@ -// SPDX-License-Identifier: GPL-2.0-or-later - -package grablogs - -import ( - "fmt" - "os" - "os/exec" - "strings" - "sync" - "time" - - log "github.com/sirupsen/logrus" - - "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/utils" -) - -var ( - ptpContainers = []string{"linuxptp-daemon-container"} -) - -func buildCommand(containerName, kubeconfigPath, logWindow string) *exec.Cmd { - params := []string{"logs", "--kubeconfig", kubeconfigPath, "--namespace=openshift-ptp", "daemonset/linuxptp-daemon", "-c", containerName} //nolint:lll //easier to read unwrapped - if logWindow != "" { - params = append(params, "--since", logWindow) - } - - cmd := exec.Command("oc", params...) - return cmd -} - -func buildFilename(outputPath, name string, timestamp time.Time) string { - return fmt.Sprintf("%s/%s-%s", outputPath, name, timestamp.Format("060102T150405")) -} - -func getLogsForContainer(cmd *exec.Cmd, filename string) { - log.Infof("Running command: %s", cmd) - outputfile, err := os.Create(filename) - utils.IfErrorExitOrPanic(err) - log.Infof("Outputting to file: %v", outputfile.Name()) - defer outputfile.Close() - cmd.Stdout = outputfile - - var stderr strings.Builder - cmd.Stderr = &stderr - - err = cmd.Run() - utils.IfErrorExitOrPanic(err) -} - -func GrabLogs(kubeconfigPath, logWindow, outputPath string) { - var wg sync.WaitGroup //nolint:varnamelen // `wg` is a common abbreviation for waitgroup. - wg.Add(len(ptpContainers)) - - now := time.Now() - for i, containerName := range ptpContainers { - log.Infof("Starting goroutine %d for %s", i, containerName) - go func(containerName string) { - defer wg.Done() - cmd := buildCommand(containerName, kubeconfigPath, logWindow) - filename := buildFilename(outputPath, containerName, now) - getLogsForContainer(cmd, filename) - }(containerName) - } - wg.Wait() -} diff --git a/pkg/loglines/dedup.go b/pkg/loglines/dedup.go new file mode 100644 index 00000000..d07fd043 --- /dev/null +++ b/pkg/loglines/dedup.go @@ -0,0 +1,224 @@ +// SPDX-License-Identifier: GPL-2.0-or-later + +package loglines + +import ( + "fmt" + "os" + "sort" + + log "github.com/sirupsen/logrus" +) + +const ( + keepGenerations = 5 +) + +func dedupGeneration(lineSlices []*LineSlice) *LineSlice { + ls1, ls2 := DedupLineSlices(lineSlices) + output := MakeSliceFromLines(MakeNewCombinedSlice(ls1.Lines, ls2.Lines), ls2.Generation) + return output +} + +// findLineIndex will find the index of a line in a slice of lines +// and will return -1 if it is not found +func findLineIndex(needle *ProcessedLine, list []*ProcessedLine) int { + checkLine := needle.Full + for i, hay := range list { + if hay.Full == checkLine { + return i + } + } + return -1 +} + +// looks for a line that exists in x without being present at the same index in y. +// +//nolint:varnamelen // x and y are just two sets of lines +func findFirstIssueIndex(x, y []*ProcessedLine) int { + for index, line := range x { + if index >= len(y) { + // we've reached the end of y so no bad lines found + break + } + if line.Full != y[index].Full { + return index + } + } + return -1 +} + +func findNextMatching(a, b []*ProcessedLine) (offset, index int) { + index = findLineIndex(a[offset], b) + if index == -1 { + // Can't find X in Y, Search for next line which is in Y + for offset = 1; offset < len(a); offset++ { + index = findLineIndex(a[offset], b) + if index != -1 { + break + } + } + } + return offset, index +} + +// fixLines will insert sequental lines missing in either x or y when stich them into the other. +// This is only done for the first issue found so you will need to call this iteratively. +// It will return the fixed slices and a flag which tells you if anything changed. +// If the lines at issueIndex are the same it will return the input slices. +// +//nolint:gocritic,varnamelen // don't want to name the return values as they should be built later, I think x, y are expressive enough names +func fixLines(x, y []*ProcessedLine, issueIndex int) ([]*ProcessedLine, []*ProcessedLine, bool) { + // confirm x[i] != y[i] + if x[issueIndex].Full == y[issueIndex].Full { + // No issue here... + return x, y, false + } + + // Check if its the y value missing in x + if findLineIndex(y[issueIndex], x[issueIndex:]) == -1 { + // lets add missing y values into x + yOffset, xIndex := findNextMatching(y[issueIndex:], x[issueIndex:]) + newX := make([]*ProcessedLine, 0, len(x)+yOffset) + newX = append(newX, x[:issueIndex]...) + newX = append(newX, y[issueIndex:issueIndex+yOffset]...) + newX = append(newX, x[issueIndex+xIndex:]...) + return newX, y, true + } + + if findLineIndex(x[issueIndex], y[issueIndex:]) == -1 { + xOffset, yIndex := findNextMatching(x[issueIndex:], y[issueIndex:]) + newY := make([]*ProcessedLine, 0, len(y)+xOffset) + newY = append(newY, y[:issueIndex]...) + newY = append(newY, x[issueIndex:issueIndex+xOffset]...) + newY = append(newY, y[issueIndex+yIndex:]...) + return x, newY, true + } + return x, y, false +} + +// processOverlap checks for incompatible lines if they are found it attempts to fix the issue +// and then if it fixes it then it dedups the fixed sets +// +//nolint:gocritic,varnamelen // don't want to name the return values as they should be built later, I think x, y are expressive enough names +func processOverlap(x, y []*ProcessedLine) ([]*ProcessedLine, []*ProcessedLine, error) { + newX := x + newY := y + issueIndex := findFirstIssueIndex(newX, newY) + if issueIndex == -1 { + return newX, newY, nil + } + var changed bool + for issueIndex != -1 { + newX, newY, changed = fixLines(newX, newY, issueIndex) + issueIndex = findFirstIssueIndex(newX, newY) + if !changed && issueIndex != -1 { + return newX, newY, fmt.Errorf("failed to resolve overlap") + } + } + // Now its been fixed lets just dedup it completely again. + dx, dy := DedupAB(newX, newY) + return dx, dy, nil +} + +//nolint:gocritic,varnamelen // don't want to name the return values as they should be built later, I think a, b are expressive enough names +func handleIncompleteOverlap(a, b []*ProcessedLine) ([]*ProcessedLine, []*ProcessedLine) { + newA, newB, err := processOverlap(a, b) + if err != nil { + issueIndex := findFirstIssueIndex(newA, newB) + log.Warning("Failed to fix issues gonna just split at the issue and retry this might lose some data") + return DedupAB(newA[:issueIndex], newB[issueIndex:]) + } + return newA, newB +} + +//nolint:gocritic,varnamelen // don't want to name the return values as they should be built later, I think a, b are expressive enough names +func DedupAB(a, b []*ProcessedLine) ([]*ProcessedLine, []*ProcessedLine) { + bFirstLineIndex := findLineIndex(b[0], a) + log.Debug("line index: ", bFirstLineIndex) + if bFirstLineIndex == -1 { + log.Debug("didn't to find first line of b") + lastLineIndex := findLineIndex(a[len(a)-1], b) + if lastLineIndex == -1 { + log.Debug("didn't to find last line of a; assuming no overlap") + return a, b + } + + // we have the index of the last line of a in b + // so b[:lastLineIndex+1] contains some of a + // lets try + return handleIncompleteOverlap(a, b) + } + + if index := findFirstIssueIndex(a[bFirstLineIndex:], b); index >= 0 { + return handleIncompleteOverlap(a, b) + } + + return a[:bFirstLineIndex], b +} + +func MakeNewCombinedSlice(x, y []*ProcessedLine) []*ProcessedLine { + r := make([]*ProcessedLine, 0, len(x)+len(y)) + r = append(r, x...) + r = append(r, y...) + return r +} + +//nolint:gocritic // don't want to name the return values as they should be built later +func DedupLineSlices(lineSlices []*LineSlice) (*LineSlice, *LineSlice) { + sort.Slice(lineSlices, func(i, j int) bool { + sdif := lineSlices[i].start.Sub(lineSlices[j].start) + if sdif == 0 { + // If start is the same then lets put the earlist end time first + return lineSlices[i].end.Sub(lineSlices[j].end) < 0 + } + return sdif < 0 + }) + + if len(lineSlices) == 1 { + return &LineSlice{}, lineSlices[0] + } + + lastLineSlice := lineSlices[len(lineSlices)-1] + lastButOneLineSlice := lineSlices[len(lineSlices)-2] + + // work backwards thought the slices + // dedupling the earlier one along the way + dedupedLines, lastLines := DedupAB(lastButOneLineSlice.Lines, lastLineSlice.Lines) + + if len(lineSlices) == 2 { //nolint:gomnd // it would obscure that its just a length of 2 + if len(dedupedLines) == 0 { + return &LineSlice{Generation: lastButOneLineSlice.Generation}, + MakeSliceFromLines(lastLines, lastLineSlice.Generation) + } + return MakeSliceFromLines(dedupedLines, lastButOneLineSlice.Generation), + MakeSliceFromLines(lastLines, lastLineSlice.Generation) + } + + resLines := dedupedLines + reference := MakeNewCombinedSlice(dedupedLines, lastLines) + + for index := len(lineSlices) - 3; index >= 0; index-- { + aLines, bLines := DedupAB(lineSlices[index].Lines, reference) + resLines = MakeNewCombinedSlice(aLines, resLines) + reference = MakeNewCombinedSlice(aLines, bLines) + } + return MakeSliceFromLines(resLines, lastButOneLineSlice.Generation), + MakeSliceFromLines(lastLines, lastLineSlice.Generation) +} + +func WriteOverlap(lines []*ProcessedLine, name string) error { + logFile, err := os.Create(name) + if err != nil { + return fmt.Errorf("failed %w", err) + } + defer logFile.Close() + + for _, line := range lines { + _, err := logFile.WriteString(line.Full + "\n") + if err != nil { + log.Error(err) + } + } + return nil +} diff --git a/pkg/loglines/dedup_test.go b/pkg/loglines/dedup_test.go new file mode 100644 index 00000000..e78d9ec5 --- /dev/null +++ b/pkg/loglines/dedup_test.go @@ -0,0 +1,138 @@ +// SPDX-License-Identifier: GPL-2.0-or-later + +package loglines_test + +import ( + "bufio" + "fmt" + "os" + "testing" + + . "github.com/onsi/ginkgo/v2" + . "github.com/onsi/gomega" + + "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/loglines" +) + +//nolint:unparam // its only one param for now but we might want more later +func loadLinesFromFile(path string, generation uint32) (*loglines.LineSlice, error) { + reader, err := os.Open(path) + if err != nil { + return &loglines.LineSlice{}, fmt.Errorf("failed to open file %s %w", path, err) + } + defer reader.Close() + scanner := bufio.NewScanner(reader) + + lines := make([]*loglines.ProcessedLine, 0) + for scanner.Scan() { + if err := scanner.Err(); err != nil { + return &loglines.LineSlice{}, fmt.Errorf("failed to read line from %s %w", path, err) + } + line, err := loglines.ProcessLine(scanner.Text()) + if err != nil { + return &loglines.LineSlice{}, fmt.Errorf("failed to process line from %s %w", path, err) + } + lines = append(lines, line) + } + return loglines.MakeSliceFromLines(lines, generation), nil +} + +var _ = Describe("Dedup AB tests", func() { + When("DedupAB is called on two line slices with complete overlap", func() { //nolint:dupl // don't want to dupl tests + It("should return an empty list and a complete set of the lines", func() { + lineSlice, err := loadLinesFromFile("test_files/all.log", 0) + if err != nil { + Panic() + } + dl1, dl2 := loglines.DedupAB(lineSlice.Lines, lineSlice.Lines) + Expect(dl1).To(BeEmpty()) + Expect(dl2).To(Equal(lineSlice.Lines)) + }) + }) + When("DedupAB is called on two line slices with no overlap", func() { //nolint:dupl // don't want to dupl tests + It("should return a both sets of the lines", func() { + lineSlice, err := loadLinesFromFile("test_files/all.log", 0) + if err != nil { + Panic() + } + dl1, dl2 := loglines.DedupAB(lineSlice.Lines[:100], lineSlice.Lines[200:300]) + Expect(dl1).To(Equal(lineSlice.Lines[:100])) + Expect(dl2).To(Equal(lineSlice.Lines[200:300])) + }) + }) + When("DedupAB is called on two line slices with some overlap", func() { //nolint:dupl // don't want to dupl tests + It("should return the first slice without the overlap and the second set of lines", func() { + lineSlice, err := loadLinesFromFile("test_files/all.log", 0) + if err != nil { + Panic() + } + dl1, dl2 := loglines.DedupAB(lineSlice.Lines[:200], lineSlice.Lines[100:300]) + Expect(dl1).To(Equal(lineSlice.Lines[:100])) + Expect(dl2).To(Equal(lineSlice.Lines[100:300])) + }) + }) + When("DedupAB is called on two line slices when second is an extension of the first", func() { //nolint:dupl // don't want to dupl tests + It("should return a empty set and a complete set", func() { + lineSlice, err := loadLinesFromFile("test_files/all.log", 0) + if err != nil { + Panic() + } + dl1, dl2 := loglines.DedupAB(lineSlice.Lines[:200], lineSlice.Lines[:300]) + Expect(dl1).To(BeEmpty()) + Expect(dl2).To(Equal(lineSlice.Lines[:300])) + }) + }) + When("cDedupAB is called on two line slices with when the second is an extension of the first, "+ + "but the first is missing the first line", func() { //nolint:dupl // don't want to dupl tests + It("should return a empty set and a complete set", func() { + lineSlice, err := loadLinesFromFile("test_files/all.log", 0) + if err != nil { + Panic() + } + dl1, dl2 := loglines.DedupAB(lineSlice.Lines[1:200], lineSlice.Lines[:300]) + Expect(dl1).To(BeEmpty()) + Expect(dl2).To(Equal(lineSlice.Lines[:300])) + }) + }) + When("DedupAB is called on two line slices with first slice is missing every 3rd line", func() { //nolint:dupl // don't want to dupl tests + It("should return an empty set and a complete set", func() { + lineSlice, err := loadLinesFromFile("test_files/all.log", 0) + if err != nil { + Panic() + } + firstSet := make([]*loglines.ProcessedLine, 0) + for i, line := range lineSlice.Lines[:200] { + if i%3 == 0 { + continue + } + firstSet = append(firstSet, line) + } + dl1, dl2 := loglines.DedupAB(firstSet, lineSlice.Lines[:300]) + Expect(dl1).To(BeEmpty()) + Expect(dl2).To(Equal(lineSlice.Lines[:300])) + }) + }) + When("DedupAB is called on two line slices with second slice is missing every 3rd line", func() { //nolint:dupl // don't want to dupl tests + It("should return an empty set and a complete set", func() { + lineSlice, err := loadLinesFromFile("test_files/all.log", 0) + if err != nil { + Panic() + } + secondSet := make([]*loglines.ProcessedLine, 0) + for i, line := range lineSlice.Lines[:300] { + if i%3 == 0 { + continue + } + secondSet = append(secondSet, line) + } + dl1, dl2 := loglines.DedupAB(secondSet, lineSlice.Lines[:300]) + Expect(dl1).To(BeEmpty()) + Expect(dl2).To(Equal(lineSlice.Lines[:300])) + }) + }) +}) + +func TestCommand(t *testing.T) { + RegisterFailHandler(Fail) + RunSpecs(t, "Loglines") +} diff --git a/pkg/loglines/lines.go b/pkg/loglines/lines.go new file mode 100644 index 00000000..76234a07 --- /dev/null +++ b/pkg/loglines/lines.go @@ -0,0 +1,248 @@ +// SPDX-License-Identifier: GPL-2.0-or-later + +package loglines + +import ( + "fmt" + "os" + "path/filepath" + "sort" + "strings" + "sync" + "time" + "unicode" + + log "github.com/sirupsen/logrus" + + "github.com/redhat-partner-solutions/vse-sync-collection-tools/pkg/utils" +) + +const ( + dumpChannelSize = 100 +) + +type ProcessedLine struct { + Timestamp time.Time + Full string + Content string + Generation uint32 +} + +func ProcessLine(line string) (*ProcessedLine, error) { + splitLine := strings.SplitN(line, " ", 2) //nolint:gomnd // moving this to a var would make the code less clear + if len(splitLine) < 2 { //nolint:gomnd // moving this to a var would make the code less clear + return nil, fmt.Errorf("failed to split line %s", line) + } + timestampPart := splitLine[0] + lineContent := splitLine[1] + timestamp, err := time.Parse(time.RFC3339, timestampPart) + if err != nil { + // This is not a value line something went wrong + return nil, fmt.Errorf("failed to process timestamp from line: '%s'", line) + } + processed := &ProcessedLine{ + Timestamp: timestamp, + Content: strings.TrimRightFunc(lineContent, unicode.IsSpace), + Full: strings.TrimRightFunc(line, unicode.IsSpace), + } + return processed, nil +} + +func NewGenerationalLockedTime(initialTime time.Time) GenerationalLockedTime { + return GenerationalLockedTime{time: initialTime} +} + +type GenerationalLockedTime struct { + time time.Time + lock sync.RWMutex + generation uint32 +} + +func (lt *GenerationalLockedTime) Time() time.Time { + lt.lock.RLock() + defer lt.lock.RUnlock() + return lt.time +} + +func (lt *GenerationalLockedTime) Generation() uint32 { + lt.lock.RLock() + defer lt.lock.RUnlock() + return lt.generation +} + +func (lt *GenerationalLockedTime) Update(update time.Time) { + lt.lock.Lock() + defer lt.lock.Unlock() + lt.time = update + lt.generation += 1 +} + +type LineSlice struct { + start time.Time + end time.Time + Lines []*ProcessedLine + Generation uint32 +} + +type Generations struct { + Store map[uint32][]*LineSlice + Dumper *GenerationDumper + Latest uint32 + Oldest uint32 +} + +type Dump struct { + slice *LineSlice + numberInGen int +} + +func NewGenerationDumper(dir string, keepLogs bool) *GenerationDumper { + return &GenerationDumper{ + dir: dir, + toDump: make(chan *Dump, dumpChannelSize), + quit: make(chan *os.Signal), + filenames: make([]string, 0), + keepLogs: keepLogs, + } +} + +type GenerationDumper struct { + dir string + toDump chan *Dump + quit chan *os.Signal + filenames []string + keepLogs bool + wg sync.WaitGroup +} + +func (dump *GenerationDumper) Start() { + dump.wg.Add(1) + go dump.dumpProcessor() +} + +func (dump *GenerationDumper) DumpLines(ls *LineSlice, numberInGen int) { + dump.toDump <- &Dump{slice: ls, numberInGen: numberInGen} +} + +func (dump *GenerationDumper) writeToFile(toDump *Dump) { + fname := filepath.Join( + dump.dir, + fmt.Sprintf("generation-%d-%d.log", toDump.slice.Generation, toDump.numberInGen), + ) + dump.filenames = append(dump.filenames, fname) + err := WriteOverlap(toDump.slice.Lines, fname) + if err != nil { + log.Errorf("failed to write generation dump file: %s", err.Error()) + } +} + +func (dump *GenerationDumper) dumpProcessor() { + defer dump.wg.Done() + for { + select { + case <-dump.quit: + log.Info("Dumping slices") + for len(dump.toDump) > 0 { + toDump := <-dump.toDump + dump.writeToFile(toDump) + } + return + case toDump := <-dump.toDump: + dump.writeToFile(toDump) + default: + time.Sleep(time.Nanosecond) + } + } +} + +func (dump *GenerationDumper) Stop() { + dump.quit <- &os.Kill + log.Debug("waiting for generation dumping to complete") + dump.wg.Wait() + + if !dump.keepLogs { + log.Debug("removing generation dump files") + utils.RemoveTempFiles(dump.dir, dump.filenames) + } +} + +func (gens *Generations) Add(lineSlice *LineSlice) { + genSlice, ok := gens.Store[lineSlice.Generation] + if !ok { + genSlice = make([]*LineSlice, 0) + } + numberInGen := len(genSlice) + gens.Store[lineSlice.Generation] = append(genSlice, lineSlice) + gens.Dumper.DumpLines(lineSlice, numberInGen) + + log.Debug("Logs: all generations: ", gens.Store) + + if gens.Latest < lineSlice.Generation { + gens.Latest = lineSlice.Generation + log.Debug("Logs: lastest updated ", gens.Latest) + log.Debug("Logs: should flush ", gens.ShouldFlush()) + } +} + +func (gens *Generations) removeOlderThan(keepGen uint32) { + log.Debug("Removing geners <", keepGen) + for g := range gens.Store { + if g < keepGen { + delete(gens.Store, g) + } + } + gens.Oldest = keepGen +} + +func (gens *Generations) ShouldFlush() bool { + return (gens.Latest-gens.Oldest > keepGenerations && + len(gens.Store) > keepGenerations) +} + +func (gens *Generations) Flush() *LineSlice { + lastGen := gens.Oldest + keepGenerations + log.Debug("Flushing generations <=", lastGen) + + gensToFlush := make([][]*LineSlice, 0) + for index, value := range gens.Store { + if index <= lastGen { + gensToFlush = append(gensToFlush, value) + } + } + result, lastSlice := gens.flush(gensToFlush) + gens.removeOlderThan(lastSlice.Generation) + gens.Store[lastSlice.Generation] = []*LineSlice{lastSlice} + return result +} + +func (gens *Generations) FlushAll() *LineSlice { + log.Debug("Flushing all generations") + gensToFlush := make([][]*LineSlice, 0) + for _, value := range gens.Store { + gensToFlush = append(gensToFlush, value) + } + result, lastSlice := gens.flush(gensToFlush) + return MakeSliceFromLines(MakeNewCombinedSlice(result.Lines, lastSlice.Lines), lastSlice.Generation) +} + +//nolint:gocritic // don't want to name the return values as they should be built later +func (gens *Generations) flush(generations [][]*LineSlice) (*LineSlice, *LineSlice) { + log.Debug("genrations: ", generations) + sort.Slice(generations, func(i, j int) bool { + return generations[i][0].Generation < generations[j][0].Generation + }) + dedupGen := make([]*LineSlice, len(generations)) + for index, gen := range generations { + dedupGen[index] = dedupGeneration(gen) + } + return DedupLineSlices(dedupGen) +} + +func MakeSliceFromLines(lines []*ProcessedLine, generation uint32) *LineSlice { + return &LineSlice{ + Lines: lines, + start: lines[0].Timestamp, + end: lines[len(lines)-1].Timestamp, + Generation: generation, + } +} diff --git a/pkg/loglines/test_files/all.log b/pkg/loglines/test_files/all.log new file mode 100644 index 00000000..0ec52533 --- /dev/null +++ b/pkg/loglines/test_files/all.log @@ -0,0 +1,1000 @@ +2023-09-12T20:45:30.577901600Z phc2sys[357138.013]: [ptp4l.0.config] CLOCK_REALTIME phc offset -7 s2 freq -10108 delay 505 +2023-09-12T20:45:30.640458927Z phc2sys[357138.075]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10103 delay 502 +2023-09-12T20:45:30.703071157Z phc2sys[357138.138]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10104 delay 514 +2023-09-12T20:45:30.765716846Z phc2sys[357138.200]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10109 delay 503 +2023-09-12T20:45:30.828263160Z phc2sys[357138.263]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10106 delay 500 +2023-09-12T20:45:30.890861110Z phc2sys[357138.326]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10106 delay 508 +2023-09-12T20:45:30.953432438Z phc2sys[357138.388]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10110 delay 503 +2023-09-12T20:45:31.000120915Z ts2phc[357138.435]: [ts2phc.0.config] nmea delay: 120642630 ns +2023-09-12T20:45:31.000120915Z ts2phc[357138.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551568.000000000 corr 0 src 1694551568.879384013 diff 0 +2023-09-12T20:45:31.000120915Z ts2phc[357138.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:31.000182560Z I0912 20:45:31.000148 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:31.016020965Z phc2sys[357138.451]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10111 delay 508 +2023-09-12T20:45:31.078611092Z phc2sys[357138.513]: [ptp4l.0.config] CLOCK_REALTIME phc offset -23 s2 freq -10131 delay 494 +2023-09-12T20:45:31.125529786Z ts2phc[357138.560]: [ts2phc.0.config] nmea sentence: GNRMC,204531.00,A,4233.01593,N,07112.87859,W,0.016,,120923,,,A,V +2023-09-12T20:45:31.125945263Z ts2phc[357138.561]: [ts2phc.0.config] nmea sentence: GNGGA,204531.00,4233.01593,N,07112.87859,W,1,05,1.98,60.2,M,-33.0,M,, +2023-09-12T20:45:31.125945263Z ts2phc[357138.561]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.76,1 +2023-09-12T20:45:31.125945263Z ts2phc[357138.561]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.76,5 +2023-09-12T20:45:31.125945263Z ts2phc[357138.561]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,27,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:31.125945263Z ts2phc[357138.561]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,26,153,21,24,09,056,17,25,44,120,23,28,49,236,23,1 +2023-09-12T20:45:31.126296251Z ts2phc[357138.561]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,21,32,69,326,23,1 +2023-09-12T20:45:31.126296251Z ts2phc[357138.561]: [ts2phc.0.config] nmea sentence: GNGST,204531.00,41,14,11,122,4.9,5.5,11 +2023-09-12T20:45:31.126296251Z ts2phc[357138.561]: [ts2phc.0.config] nmea sentence: GNZDA,204531.00,12,09,2023,00,00 +2023-09-12T20:45:31.126296251Z ts2phc[357138.561]: [ts2phc.0.config] nmea sentence: GNGBS,204531.00,4.9,5.5,10.8,,,,,, +2023-09-12T20:45:31.134443813Z gnss[1694551531]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:31.141184660Z phc2sys[357138.576]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10112 delay 503 +2023-09-12T20:45:31.171022714Z I0912 20:45:31.171003 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:31.171022714Z I0912 20:45:31.171017 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:31.171041863Z I0912 20:45:31.171023 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:31.176150794Z dpll[1694551531]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -1 phase_status 3 s2 +2023-09-12T20:45:31.203770247Z phc2sys[357138.639]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10109 delay 502 +2023-09-12T20:45:31.266370278Z phc2sys[357138.701]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10110 delay 503 +2023-09-12T20:45:31.328940931Z phc2sys[357138.764]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10111 delay 503 +2023-09-12T20:45:31.391509847Z phc2sys[357138.826]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10109 delay 503 +2023-09-12T20:45:31.454099121Z phc2sys[357138.889]: [ptp4l.0.config] CLOCK_REALTIME phc offset 8 s2 freq -10103 delay 495 +2023-09-12T20:45:31.516671480Z phc2sys[357138.951]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10101 delay 502 +2023-09-12T20:45:31.579257823Z phc2sys[357139.014]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10099 delay 515 +2023-09-12T20:45:31.641865759Z phc2sys[357139.077]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10100 delay 503 +2023-09-12T20:45:31.704457431Z phc2sys[357139.139]: [ptp4l.0.config] CLOCK_REALTIME phc offset 11 s2 freq -10092 delay 503 +2023-09-12T20:45:31.767075268Z phc2sys[357139.202]: [ptp4l.0.config] CLOCK_REALTIME phc offset 8 s2 freq -10092 delay 502 +2023-09-12T20:45:31.829642022Z phc2sys[357139.264]: [ptp4l.0.config] CLOCK_REALTIME phc offset 10 s2 freq -10087 delay 504 +2023-09-12T20:45:31.892289456Z phc2sys[357139.327]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10087 delay 509 +2023-09-12T20:45:31.954811569Z phc2sys[357139.390]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10087 delay 502 +2023-09-12T20:45:32.000069705Z ts2phc[357139.435]: [ts2phc.0.config] nmea delay: 125470684 ns +2023-09-12T20:45:32.000069705Z ts2phc[357139.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551569.000000000 corr 0 src 1694551569.874553125 diff 0 +2023-09-12T20:45:32.000069705Z ts2phc[357139.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:32.010207128Z I0912 20:45:32.010186 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:32.017384131Z phc2sys[357139.452]: [ptp4l.0.config] CLOCK_REALTIME phc offset 8 s2 freq -10083 delay 502 +2023-09-12T20:45:32.079960898Z phc2sys[357139.515]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10084 delay 509 +2023-09-12T20:45:32.110307879Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GNRMC,204532.00,A,4233.01593,N,07112.87859,W,0.016,,120923,,,A,V +2023-09-12T20:45:32.110307879Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GNGGA,204532.00,4233.01593,N,07112.87859,W,1,05,1.98,60.1,M,-33.0,M,, +2023-09-12T20:45:32.110307879Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.76,1 +2023-09-12T20:45:32.110307879Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.76,5 +2023-09-12T20:45:32.110350123Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:32.110350123Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,26,153,20,24,09,056,17,25,44,120,23,28,49,236,23,1 +2023-09-12T20:45:32.110350123Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,22,32,69,326,23,1 +2023-09-12T20:45:32.110350123Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GNGST,204532.00,42,14,11,122,4.9,5.5,11 +2023-09-12T20:45:32.110350123Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GNZDA,204532.00,12,09,2023,00,00 +2023-09-12T20:45:32.110444476Z ts2phc[357139.545]: [ts2phc.0.config] nmea sentence: GNGBS,204532.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:32.113613408Z gnss[1694551532]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:32.142543591Z phc2sys[357139.577]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10083 delay 503 +2023-09-12T20:45:32.171600541Z I0912 20:45:32.171580 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:32.171600541Z I0912 20:45:32.171593 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:32.171627693Z I0912 20:45:32.171599 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:32.175738420Z dpll[1694551532]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -2 phase_status 3 s2 +2023-09-12T20:45:32.205133395Z phc2sys[357139.640]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10087 delay 508 +2023-09-12T20:45:32.267705176Z phc2sys[357139.703]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10080 delay 501 +2023-09-12T20:45:32.330293761Z phc2sys[357139.765]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10082 delay 502 +2023-09-12T20:45:32.392863087Z phc2sys[357139.828]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10084 delay 502 +2023-09-12T20:45:32.455435186Z phc2sys[357139.890]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10085 delay 503 +2023-09-12T20:45:32.518021421Z phc2sys[357139.953]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10088 delay 503 +2023-09-12T20:45:32.580587753Z phc2sys[357140.015]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10084 delay 501 +2023-09-12T20:45:32.643158591Z phc2sys[357140.078]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10087 delay 503 +2023-09-12T20:45:32.705762952Z phc2sys[357140.141]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10089 delay 501 +2023-09-12T20:45:32.768358201Z phc2sys[357140.203]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10090 delay 500 +2023-09-12T20:45:32.830948183Z phc2sys[357140.266]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10090 delay 504 +2023-09-12T20:45:32.893517560Z phc2sys[357140.328]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10093 delay 498 +2023-09-12T20:45:32.956090062Z phc2sys[357140.391]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10093 delay 503 +2023-09-12T20:45:33.000066773Z ts2phc[357140.435]: [ts2phc.0.config] nmea delay: 109923033 ns +2023-09-12T20:45:33.000066773Z ts2phc[357140.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551570.000000000 corr 0 src 1694551570.890101077 diff 0 +2023-09-12T20:45:33.000117021Z ts2phc[357140.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:33.006273907Z I0912 20:45:33.006254 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:33.018661166Z phc2sys[357140.453]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10093 delay 503 +2023-09-12T20:45:33.081397193Z phc2sys[357140.516]: [ptp4l.0.config] CLOCK_REALTIME phc offset -9 s2 freq -10100 delay 505 +2023-09-12T20:45:33.135543428Z ts2phc[357140.570]: [ts2phc.0.config] nmea sentence: GNRMC,204533.00,A,4233.01594,N,07112.87859,W,0.016,,120923,,,A,V +2023-09-12T20:45:33.136129930Z ts2phc[357140.571]: [ts2phc.0.config] nmea sentence: GNGGA,204533.00,4233.01594,N,07112.87859,W,1,05,1.98,60.1,M,-33.0,M,, +2023-09-12T20:45:33.136129930Z ts2phc[357140.571]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.76,1 +2023-09-12T20:45:33.136155932Z ts2phc[357140.571]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.76,5 +2023-09-12T20:45:33.136155932Z ts2phc[357140.571]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:33.136155932Z ts2phc[357140.571]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,26,153,20,24,09,056,16,25,44,120,22,28,49,236,23,1 +2023-09-12T20:45:33.136155932Z ts2phc[357140.571]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,21,32,69,326,24,1 +2023-09-12T20:45:33.136155932Z ts2phc[357140.571]: [ts2phc.0.config] nmea sentence: GNGST,204533.00,41,14,11,122,4.9,5.5,11 +2023-09-12T20:45:33.136155932Z ts2phc[357140.571]: [ts2phc.0.config] nmea sentence: GNZDA,204533.00,12,09,2023,00,00 +2023-09-12T20:45:33.136155932Z ts2phc[357140.571]: [ts2phc.0.config] nmea sentence: GNGBS,204533.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:33.140295785Z gnss[1694551533]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:33.143842376Z phc2sys[357140.579]: [ptp4l.0.config] CLOCK_REALTIME phc offset -9 s2 freq -10103 delay 503 +2023-09-12T20:45:33.171769600Z I0912 20:45:33.171745 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:33.171769600Z I0912 20:45:33.171761 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:33.171801265Z I0912 20:45:33.171769 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:33.182006993Z dpll[1694551533]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 2 phase_status 3 s2 +2023-09-12T20:45:33.206420896Z phc2sys[357140.641]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10101 delay 498 +2023-09-12T20:45:33.269019066Z phc2sys[357140.704]: [ptp4l.0.config] CLOCK_REALTIME phc offset -8 s2 freq -10106 delay 503 +2023-09-12T20:45:33.331608834Z phc2sys[357140.766]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10106 delay 511 +2023-09-12T20:45:33.394206626Z phc2sys[357140.829]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10108 delay 504 +2023-09-12T20:45:33.456767387Z phc2sys[357140.892]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10103 delay 502 +2023-09-12T20:45:33.519342034Z phc2sys[357140.954]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10105 delay 503 +2023-09-12T20:45:33.582005534Z phc2sys[357141.017]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10107 delay 507 +2023-09-12T20:45:33.644532313Z phc2sys[357141.079]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10110 delay 514 +2023-09-12T20:45:33.707136459Z phc2sys[357141.142]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10110 delay 504 +2023-09-12T20:45:33.769706208Z phc2sys[357141.204]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10106 delay 503 +2023-09-12T20:45:33.832297265Z phc2sys[357141.267]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10104 delay 502 +2023-09-12T20:45:33.894884259Z phc2sys[357141.330]: [ptp4l.0.config] CLOCK_REALTIME phc offset 13 s2 freq -10093 delay 473 +2023-09-12T20:45:33.957464312Z phc2sys[357141.392]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10104 delay 502 +2023-09-12T20:45:34.000090010Z ts2phc[357141.435]: [ts2phc.0.config] nmea delay: 135358057 ns +2023-09-12T20:45:34.000121440Z ts2phc[357141.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551571.000000000 corr 0 src 1694551571.864665739 diff 0 +2023-09-12T20:45:34.000121440Z ts2phc[357141.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:34.003349720Z I0912 20:45:34.003330 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:34.020041367Z phc2sys[357141.455]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10106 delay 502 +2023-09-12T20:45:34.082613037Z phc2sys[357141.517]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10104 delay 503 +2023-09-12T20:45:34.145202981Z phc2sys[357141.580]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10107 delay 512 +2023-09-12T20:45:34.169154998Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GNRMC,204534.00,A,4233.01594,N,07112.87860,W,0.016,,120923,,,A,V +2023-09-12T20:45:34.169477845Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GNGGA,204534.00,4233.01594,N,07112.87860,W,1,05,1.98,60.1,M,-33.0,M,, +2023-09-12T20:45:34.169517522Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.76,1 +2023-09-12T20:45:34.169562899Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.76,5 +2023-09-12T20:45:34.169588682Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,26,12,33,066,22,21,20,287,17,1 +2023-09-12T20:45:34.169613558Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,26,153,20,24,09,056,16,25,44,120,22,28,49,236,23,1 +2023-09-12T20:45:34.169660915Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,22,32,69,326,23,1 +2023-09-12T20:45:34.169697712Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GNGST,204534.00,42,14,11,122,4.9,5.5,11 +2023-09-12T20:45:34.169750280Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GNZDA,204534.00,12,09,2023,00,00 +2023-09-12T20:45:34.169773514Z ts2phc[357141.604]: [ts2phc.0.config] nmea sentence: GNGBS,204534.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:34.171809787Z I0912 20:45:34.171791 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:34.171809787Z I0912 20:45:34.171804 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:34.171832354Z I0912 20:45:34.171810 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:34.177957620Z gnss[1694551534]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:34.178011307Z dpll[1694551534]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 1 phase_status 3 s2 +2023-09-12T20:45:34.207782660Z phc2sys[357141.643]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10105 delay 499 +2023-09-12T20:45:34.270376859Z phc2sys[357141.705]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10108 delay 502 +2023-09-12T20:45:34.332942014Z phc2sys[357141.768]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10104 delay 502 +2023-09-12T20:45:34.395557153Z phc2sys[357141.830]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10106 delay 503 +2023-09-12T20:45:34.458130419Z phc2sys[357141.893]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10103 delay 503 +2023-09-12T20:45:34.520723811Z phc2sys[357141.956]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10104 delay 497 +2023-09-12T20:45:34.583291578Z phc2sys[357142.018]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10105 delay 503 +2023-09-12T20:45:34.645869330Z phc2sys[357142.081]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10100 delay 503 +2023-09-12T20:45:34.708436564Z phc2sys[357142.143]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10103 delay 503 +2023-09-12T20:45:34.771032444Z phc2sys[357142.206]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10101 delay 508 +2023-09-12T20:45:34.833607345Z phc2sys[357142.268]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10097 delay 502 +2023-09-12T20:45:34.896191738Z phc2sys[357142.331]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10099 delay 501 +2023-09-12T20:45:34.958764463Z phc2sys[357142.394]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10099 delay 510 +2023-09-12T20:45:35.000080178Z ts2phc[357142.435]: [ts2phc.0.config] nmea delay: 168953517 ns +2023-09-12T20:45:35.000080178Z ts2phc[357142.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551572.000000000 corr 0 src 1694551572.831080776 diff 0 +2023-09-12T20:45:35.000131003Z ts2phc[357142.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:35.009294566Z I0912 20:45:35.009272 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:35.021354636Z phc2sys[357142.456]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10099 delay 509 +2023-09-12T20:45:35.083991190Z phc2sys[357142.519]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10099 delay 512 +2023-09-12T20:45:35.118756314Z ts2phc[357142.553]: [ts2phc.0.config] nmea sentence: GNRMC,204535.00,A,4233.01593,N,07112.87861,W,0.016,,120923,,,A,V +2023-09-12T20:45:35.119280658Z ts2phc[357142.554]: [ts2phc.0.config] nmea sentence: GNGGA,204535.00,4233.01593,N,07112.87861,W,1,05,1.98,60.1,M,-33.0,M,, +2023-09-12T20:45:35.119336499Z ts2phc[357142.554]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.76,1 +2023-09-12T20:45:35.119374475Z ts2phc[357142.554]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.76,5 +2023-09-12T20:45:35.119401712Z ts2phc[357142.554]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:35.119428485Z ts2phc[357142.554]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,16,25,44,120,22,28,49,236,23,1 +2023-09-12T20:45:35.119453466Z ts2phc[357142.554]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,21,32,69,326,23,1 +2023-09-12T20:45:35.119478714Z ts2phc[357142.554]: [ts2phc.0.config] nmea sentence: GNGST,204535.00,42,14,11,122,4.9,5.5,11 +2023-09-12T20:45:35.119505502Z ts2phc[357142.554]: [ts2phc.0.config] nmea sentence: GNZDA,204535.00,12,09,2023,00,00 +2023-09-12T20:45:35.119538254Z ts2phc[357142.554]: [ts2phc.0.config] nmea sentence: GNGBS,204535.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:35.121653241Z gnss[1694551535]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:35.146602065Z phc2sys[357142.581]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10098 delay 506 +2023-09-12T20:45:35.171473219Z I0912 20:45:35.171442 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:35.172176209Z I0912 20:45:35.171825 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:35.172176209Z I0912 20:45:35.171837 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:35.175044031Z dpll[1694551535]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 1 phase_status 3 s2 +2023-09-12T20:45:35.209177846Z phc2sys[357142.644]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10098 delay 500 +2023-09-12T20:45:35.271761470Z phc2sys[357142.707]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10102 delay 503 +2023-09-12T20:45:35.334346274Z phc2sys[357142.769]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10099 delay 497 +2023-09-12T20:45:35.396915142Z phc2sys[357142.832]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10099 delay 499 +2023-09-12T20:45:35.459494833Z phc2sys[357142.894]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10096 delay 504 +2023-09-12T20:45:35.522077931Z phc2sys[357142.957]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10096 delay 506 +2023-09-12T20:45:35.584725802Z phc2sys[357143.019]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10098 delay 507 +2023-09-12T20:45:35.647372311Z phc2sys[357143.082]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10096 delay 510 +2023-09-12T20:45:35.709913243Z phc2sys[357143.145]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10097 delay 502 +2023-09-12T20:45:35.772483372Z phc2sys[357143.207]: [ptp4l.0.config] CLOCK_REALTIME phc offset 17 s2 freq -10080 delay 485 +2023-09-12T20:45:35.835066895Z phc2sys[357143.270]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10096 delay 503 +2023-09-12T20:45:35.897636519Z phc2sys[357143.332]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10096 delay 502 +2023-09-12T20:45:35.960209495Z phc2sys[357143.395]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10098 delay 503 +2023-09-12T20:45:36.000167253Z ts2phc[357143.435]: [ts2phc.0.config] nmea delay: 118635224 ns +2023-09-12T20:45:36.000167253Z ts2phc[357143.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551573.000000000 corr 0 src 1694551573.881389766 diff 0 +2023-09-12T20:45:36.000227050Z ts2phc[357143.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:36.000335284Z I0912 20:45:36.000313 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:36.022786353Z phc2sys[357143.458]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10094 delay 501 +2023-09-12T20:45:36.085369983Z phc2sys[357143.520]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10090 delay 502 +2023-09-12T20:45:36.109479963Z ts2phc[357143.544]: [ts2phc.0.config] nmea sentence: GNRMC,204536.00,A,4233.01594,N,07112.87862,W,0.016,,120923,,,A,V +2023-09-12T20:45:36.109970965Z ts2phc[357143.545]: [ts2phc.0.config] nmea sentence: GNGGA,204536.00,4233.01594,N,07112.87862,W,1,05,1.98,60.1,M,-33.0,M,, +2023-09-12T20:45:36.110021129Z ts2phc[357143.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.76,1 +2023-09-12T20:45:36.110064001Z ts2phc[357143.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.76,5 +2023-09-12T20:45:36.110091689Z ts2phc[357143.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:36.110122253Z ts2phc[357143.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,17,25,44,120,22,28,49,236,23,1 +2023-09-12T20:45:36.110122253Z ts2phc[357143.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,21,32,69,326,23,1 +2023-09-12T20:45:36.110122253Z ts2phc[357143.545]: [ts2phc.0.config] nmea sentence: GNGST,204536.00,42,14,11,122,4.9,5.5,11 +2023-09-12T20:45:36.110122253Z ts2phc[357143.545]: [ts2phc.0.config] nmea sentence: GNZDA,204536.00,12,09,2023,00,00 +2023-09-12T20:45:36.110122253Z ts2phc[357143.545]: [ts2phc.0.config] nmea sentence: GNGBS,204536.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:36.113227594Z gnss[1694551536]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:36.147947026Z phc2sys[357143.583]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10093 delay 496 +2023-09-12T20:45:36.171617494Z I0912 20:45:36.171597 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:36.171617494Z I0912 20:45:36.171612 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:36.171645729Z I0912 20:45:36.171619 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:36.174756847Z dpll[1694551536]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 0 phase_status 3 s2 +2023-09-12T20:45:36.210542813Z phc2sys[357143.645]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10097 delay 503 +2023-09-12T20:45:36.273159360Z phc2sys[357143.708]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10098 delay 502 +2023-09-12T20:45:36.335719267Z phc2sys[357143.771]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10094 delay 500 +2023-09-12T20:45:36.398288003Z phc2sys[357143.833]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10094 delay 503 +2023-09-12T20:45:36.460876865Z phc2sys[357143.896]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10100 delay 503 +2023-09-12T20:45:36.523446339Z phc2sys[357143.958]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10095 delay 503 +2023-09-12T20:45:36.586025794Z phc2sys[357144.021]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10092 delay 503 +2023-09-12T20:45:36.649121533Z phc2sys[357144.083]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10096 delay 507 +2023-09-12T20:45:36.711737535Z phc2sys[357144.146]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10098 delay 504 +2023-09-12T20:45:36.773885533Z phc2sys[357144.209]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10098 delay 502 +2023-09-12T20:45:36.836557741Z phc2sys[357144.271]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10100 delay 509 +2023-09-12T20:45:36.899100958Z phc2sys[357144.334]: [ptp4l.0.config] CLOCK_REALTIME phc offset -7 s2 freq -10104 delay 503 +2023-09-12T20:45:36.961699539Z phc2sys[357144.396]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10099 delay 502 +2023-09-12T20:45:37.000080615Z ts2phc[357144.435]: [ts2phc.0.config] nmea delay: 109429817 ns +2023-09-12T20:45:37.000080615Z ts2phc[357144.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551574.000000000 corr 0 src 1694551574.890597428 diff 0 +2023-09-12T20:45:37.000080615Z ts2phc[357144.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:37.008282923Z I0912 20:45:37.008260 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:37.024281809Z phc2sys[357144.459]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10102 delay 508 +2023-09-12T20:45:37.086889064Z phc2sys[357144.522]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10101 delay 494 +2023-09-12T20:45:37.132241966Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GNRMC,204537.00,A,4233.01595,N,07112.87862,W,0.016,,120923,,,A,V +2023-09-12T20:45:37.132526493Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GNGGA,204537.00,4233.01595,N,07112.87862,W,1,05,1.98,60.1,M,-33.0,M,, +2023-09-12T20:45:37.132526493Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.76,1 +2023-09-12T20:45:37.132539884Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.76,5 +2023-09-12T20:45:37.132539884Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:37.132539884Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,21,24,09,056,17,25,45,120,22,28,49,236,23,1 +2023-09-12T20:45:37.132539884Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,21,32,69,326,23,1 +2023-09-12T20:45:37.132613130Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GNGST,204537.00,41,14,11,122,4.9,5.5,11 +2023-09-12T20:45:37.132623547Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GNZDA,204537.00,12,09,2023,00,00 +2023-09-12T20:45:37.132706366Z ts2phc[357144.567]: [ts2phc.0.config] nmea sentence: GNGBS,204537.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:37.141894002Z gnss[1694551537]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:37.149513013Z phc2sys[357144.584]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10101 delay 503 +2023-09-12T20:45:37.171495948Z I0912 20:45:37.171475 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:37.171495948Z I0912 20:45:37.171490 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:37.171522570Z I0912 20:45:37.171496 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:37.173619017Z dpll[1694551537]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -2 phase_status 3 s2 +2023-09-12T20:45:37.212089603Z phc2sys[357144.647]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10101 delay 503 +2023-09-12T20:45:37.274643473Z phc2sys[357144.709]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10103 delay 502 +2023-09-12T20:45:37.337220863Z phc2sys[357144.772]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10107 delay 503 +2023-09-12T20:45:37.399802161Z phc2sys[357144.835]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10104 delay 503 +2023-09-12T20:45:37.462371616Z phc2sys[357144.897]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10105 delay 503 +2023-09-12T20:45:37.525006437Z phc2sys[357144.960]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10108 delay 506 +2023-09-12T20:45:37.587548191Z phc2sys[357145.022]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10103 delay 502 +2023-09-12T20:45:37.650226268Z phc2sys[357145.085]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10104 delay 510 +2023-09-12T20:45:37.712784760Z phc2sys[357145.148]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10104 delay 509 +2023-09-12T20:45:37.775388214Z phc2sys[357145.210]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10107 delay 503 +2023-09-12T20:45:37.837974109Z phc2sys[357145.273]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10106 delay 503 +2023-09-12T20:45:37.900544681Z phc2sys[357145.335]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10108 delay 503 +2023-09-12T20:45:37.963182916Z phc2sys[357145.398]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10107 delay 502 +2023-09-12T20:45:38.000072139Z ts2phc[357145.435]: [ts2phc.0.config] nmea delay: 132195182 ns +2023-09-12T20:45:38.000129282Z ts2phc[357145.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551575.000000000 corr 0 src 1694551575.867828231 diff 0 +2023-09-12T20:45:38.000158486Z ts2phc[357145.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:38.006330602Z I0912 20:45:38.006286 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:38.025738317Z phc2sys[357145.461]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10100 delay 502 +2023-09-12T20:45:38.088382717Z phc2sys[357145.523]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10101 delay 507 +2023-09-12T20:45:38.110200684Z ts2phc[357145.545]: [ts2phc.0.config] nmea sentence: GNRMC,204538.00,A,4233.01594,N,07112.87864,W,0.016,,120923,,,A,V +2023-09-12T20:45:38.110555418Z ts2phc[357145.545]: [ts2phc.0.config] nmea sentence: GNGGA,204538.00,4233.01594,N,07112.87864,W,1,05,1.98,60.0,M,-33.0,M,, +2023-09-12T20:45:38.110593995Z ts2phc[357145.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.76,1 +2023-09-12T20:45:38.110634754Z ts2phc[357145.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.76,5 +2023-09-12T20:45:38.110677673Z ts2phc[357145.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,27,12,33,066,22,21,20,287,19,1 +2023-09-12T20:45:38.110720368Z ts2phc[357145.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,17,25,45,120,22,28,49,236,22,1 +2023-09-12T20:45:38.110783259Z ts2phc[357145.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,21,32,69,326,24,1 +2023-09-12T20:45:38.110811358Z ts2phc[357145.545]: [ts2phc.0.config] nmea sentence: GNGST,204538.00,41,14,11,122,4.9,5.5,11 +2023-09-12T20:45:38.110842017Z ts2phc[357145.545]: [ts2phc.0.config] nmea sentence: GNZDA,204538.00,12,09,2023,00,00 +2023-09-12T20:45:38.110871241Z ts2phc[357145.546]: [ts2phc.0.config] nmea sentence: GNGBS,204538.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:38.119070599Z gnss[1694551538]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:38.150878907Z phc2sys[357145.586]: [ptp4l.0.config] CLOCK_REALTIME phc offset 18 s2 freq -10085 delay 474 +2023-09-12T20:45:38.171561827Z I0912 20:45:38.171542 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:38.171561827Z I0912 20:45:38.171556 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:38.171587136Z I0912 20:45:38.171561 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:38.180798911Z dpll[1694551538]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -3 phase_status 3 s2 +2023-09-12T20:45:38.213458729Z phc2sys[357145.648]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10094 delay 514 +2023-09-12T20:45:38.276038443Z phc2sys[357145.711]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10095 delay 501 +2023-09-12T20:45:38.338658515Z phc2sys[357145.773]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10091 delay 504 +2023-09-12T20:45:38.401242480Z phc2sys[357145.836]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10095 delay 502 +2023-09-12T20:45:38.463821581Z phc2sys[357145.899]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10094 delay 504 +2023-09-12T20:45:38.526397624Z phc2sys[357145.961]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10096 delay 503 +2023-09-12T20:45:38.589000355Z phc2sys[357146.024]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10091 delay 500 +2023-09-12T20:45:38.651599629Z phc2sys[357146.086]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10092 delay 507 +2023-09-12T20:45:38.714160664Z phc2sys[357146.149]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10087 delay 503 +2023-09-12T20:45:38.776774925Z phc2sys[357146.212]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10084 delay 502 +2023-09-12T20:45:38.839325036Z phc2sys[357146.274]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10089 delay 502 +2023-09-12T20:45:38.901903833Z phc2sys[357146.337]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10084 delay 503 +2023-09-12T20:45:38.964486471Z phc2sys[357146.399]: [ptp4l.0.config] CLOCK_REALTIME phc offset 22 s2 freq -10066 delay 477 +2023-09-12T20:45:39.000060969Z ts2phc[357146.435]: [ts2phc.0.config] nmea delay: 110101427 ns +2023-09-12T20:45:39.000060969Z ts2phc[357146.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551576.000000000 corr 0 src 1694551576.889920902 diff 0 +2023-09-12T20:45:39.000138791Z ts2phc[357146.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:39.001207652Z I0912 20:45:39.001189 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:39.027086615Z phc2sys[357146.462]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10085 delay 508 +2023-09-12T20:45:39.089655193Z phc2sys[357146.524]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10086 delay 503 +2023-09-12T20:45:39.121929162Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GNRMC,204539.00,A,4233.01593,N,07112.87866,W,0.016,,120923,,,A,V +2023-09-12T20:45:39.122401547Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GNGGA,204539.00,4233.01593,N,07112.87866,W,1,05,1.98,60.0,M,-33.0,M,, +2023-09-12T20:45:39.122445783Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.77,1 +2023-09-12T20:45:39.122488350Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.77,5 +2023-09-12T20:45:39.122513106Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,26,12,33,066,23,21,20,287,19,1 +2023-09-12T20:45:39.122539217Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,17,25,45,120,23,28,49,236,23,1 +2023-09-12T20:45:39.122572399Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,21,32,69,326,24,1 +2023-09-12T20:45:39.122572399Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GNGST,204539.00,41,14,11,122,4.9,5.5,11 +2023-09-12T20:45:39.122572399Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GNZDA,204539.00,12,09,2023,00,00 +2023-09-12T20:45:39.122572399Z ts2phc[357146.557]: [ts2phc.0.config] nmea sentence: GNGBS,204539.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:39.124644986Z gnss[1694551539]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:39.152356565Z phc2sys[357146.587]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10089 delay 514 +2023-09-12T20:45:39.171214746Z I0912 20:45:39.171196 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:39.171214746Z I0912 20:45:39.171209 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:39.171239433Z I0912 20:45:39.171215 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:39.176309469Z dpll[1694551539]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 2 phase_status 3 s2 +2023-09-12T20:45:39.214823102Z phc2sys[357146.650]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10090 delay 503 +2023-09-12T20:45:39.277391329Z phc2sys[357146.712]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10088 delay 502 +2023-09-12T20:45:39.339972118Z phc2sys[357146.775]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10092 delay 513 +2023-09-12T20:45:39.402551743Z phc2sys[357146.837]: [ptp4l.0.config] CLOCK_REALTIME phc offset -8 s2 freq -10096 delay 503 +2023-09-12T20:45:39.465123485Z phc2sys[357146.900]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10093 delay 503 +2023-09-12T20:45:39.527695072Z phc2sys[357146.962]: [ptp4l.0.config] CLOCK_REALTIME phc offset -7 s2 freq -10098 delay 504 +2023-09-12T20:45:39.590317105Z phc2sys[357147.025]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10100 delay 508 +2023-09-12T20:45:39.652908785Z phc2sys[357147.088]: [ptp4l.0.config] CLOCK_REALTIME phc offset -8 s2 freq -10103 delay 503 +2023-09-12T20:45:39.715494393Z phc2sys[357147.150]: [ptp4l.0.config] CLOCK_REALTIME phc offset -8 s2 freq -10106 delay 503 +2023-09-12T20:45:39.778092086Z phc2sys[357147.213]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10102 delay 502 +2023-09-12T20:45:39.840643337Z phc2sys[357147.275]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10104 delay 503 +2023-09-12T20:45:39.903209820Z phc2sys[357147.338]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10105 delay 503 +2023-09-12T20:45:39.965792862Z phc2sys[357147.401]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10105 delay 503 +2023-09-12T20:45:40.000070843Z ts2phc[357147.435]: [ts2phc.0.config] nmea delay: 121843376 ns +2023-09-12T20:45:40.000070843Z ts2phc[357147.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551577.000000000 corr 0 src 1694551577.878179855 diff 0 +2023-09-12T20:45:40.000070843Z ts2phc[357147.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:40.007255983Z I0912 20:45:40.007226 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:40.028369712Z phc2sys[357147.463]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10103 delay 503 +2023-09-12T20:45:40.090961365Z phc2sys[357147.526]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10107 delay 497 +2023-09-12T20:45:40.111858783Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GNRMC,204540.00,A,4233.01594,N,07112.87868,W,0.016,,120923,,,A,V +2023-09-12T20:45:40.112317571Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GNGGA,204540.00,4233.01594,N,07112.87868,W,1,05,1.98,59.9,M,-33.0,M,, +2023-09-12T20:45:40.112368575Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.77,1 +2023-09-12T20:45:40.112412260Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.77,5 +2023-09-12T20:45:40.112438223Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,27,12,33,066,22,21,20,287,20,1 +2023-09-12T20:45:40.112465938Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,17,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:40.112465938Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,22,32,69,326,25,1 +2023-09-12T20:45:40.112465938Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GNGST,204540.00,40,14,11,122,4.9,5.5,11 +2023-09-12T20:45:40.112465938Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GNZDA,204540.00,12,09,2023,00,00 +2023-09-12T20:45:40.112465938Z ts2phc[357147.547]: [ts2phc.0.config] nmea sentence: GNGBS,204540.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:40.121224214Z gnss[1694551540]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:40.153557244Z phc2sys[357147.588]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10106 delay 501 +2023-09-12T20:45:40.171097894Z I0912 20:45:40.171077 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:40.171097894Z I0912 20:45:40.171093 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:40.171122164Z I0912 20:45:40.171099 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:40.172158035Z dpll[1694551540]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 0 phase_status 3 s2 +2023-09-12T20:45:40.216106079Z phc2sys[357147.651]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10111 delay 503 +2023-09-12T20:45:40.278743207Z phc2sys[357147.713]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10109 delay 499 +2023-09-12T20:45:40.341285079Z phc2sys[357147.776]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10109 delay 503 +2023-09-12T20:45:40.403855152Z phc2sys[357147.839]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10110 delay 502 +2023-09-12T20:45:40.466442221Z phc2sys[357147.901]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10111 delay 503 +2023-09-12T20:45:40.529090408Z phc2sys[357147.964]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10105 delay 503 +2023-09-12T20:45:40.591615377Z phc2sys[357148.026]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10107 delay 504 +2023-09-12T20:45:40.654212840Z phc2sys[357148.089]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10108 delay 502 +2023-09-12T20:45:40.716806868Z phc2sys[357148.152]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10106 delay 502 +2023-09-12T20:45:40.779417559Z phc2sys[357148.214]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10107 delay 502 +2023-09-12T20:45:40.842016543Z phc2sys[357148.277]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10107 delay 503 +2023-09-12T20:45:40.904587202Z phc2sys[357148.339]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10108 delay 503 +2023-09-12T20:45:40.967187166Z phc2sys[357148.402]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10102 delay 503 +2023-09-12T20:45:41.000110394Z ts2phc[357148.435]: [ts2phc.0.config] nmea delay: 111809969 ns +2023-09-12T20:45:41.000110394Z ts2phc[357148.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551578.000000000 corr 0 src 1694551578.888216267 diff 0 +2023-09-12T20:45:41.000110394Z ts2phc[357148.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:41.006430566Z I0912 20:45:41.006410 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:41.029831421Z phc2sys[357148.465]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10103 delay 505 +2023-09-12T20:45:41.092362581Z phc2sys[357148.527]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10103 delay 503 +2023-09-12T20:45:41.109207765Z ts2phc[357148.543]: [ts2phc.0.config] nmea sentence: GNRMC,204541.00,A,4233.01593,N,07112.87870,W,0.016,,120923,,,A,V +2023-09-12T20:45:41.109207765Z ts2phc[357148.544]: [ts2phc.0.config] nmea sentence: GNGGA,204541.00,4233.01593,N,07112.87870,W,1,05,1.98,59.9,M,-33.0,M,, +2023-09-12T20:45:41.109207765Z ts2phc[357148.544]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.77,1 +2023-09-12T20:45:41.109207765Z ts2phc[357148.544]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.77,5 +2023-09-12T20:45:41.109207765Z ts2phc[357148.544]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,27,12,33,066,22,21,20,287,19,1 +2023-09-12T20:45:41.109207765Z ts2phc[357148.544]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,19,24,09,056,16,25,45,120,22,28,50,237,23,1 +2023-09-12T20:45:41.109207765Z ts2phc[357148.544]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,22,32,69,326,25,1 +2023-09-12T20:45:41.109207765Z ts2phc[357148.544]: [ts2phc.0.config] nmea sentence: GNGST,204541.00,41,14,11,122,4.9,5.5,11 +2023-09-12T20:45:41.109207765Z ts2phc[357148.544]: [ts2phc.0.config] nmea sentence: GNZDA,204541.00,12,09,2023,00,00 +2023-09-12T20:45:41.109259235Z ts2phc[357148.544]: [ts2phc.0.config] nmea sentence: GNGBS,204541.00,4.9,5.5,10.9,,,,,, +2023-09-12T20:45:41.119413393Z gnss[1694551541]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:41.154970653Z phc2sys[357148.590]: [ptp4l.0.config] CLOCK_REALTIME phc offset 10 s2 freq -10094 delay 503 +2023-09-12T20:45:41.171542573Z I0912 20:45:41.171522 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:41.171542573Z I0912 20:45:41.171536 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:41.171578579Z I0912 20:45:41.171543 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:41.180678036Z dpll[1694551541]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -2 phase_status 3 s2 +2023-09-12T20:45:41.217526389Z phc2sys[357148.652]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10099 delay 502 +2023-09-12T20:45:41.280154785Z phc2sys[357148.715]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10098 delay 504 +2023-09-12T20:45:41.342715603Z phc2sys[357148.777]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10096 delay 501 +2023-09-12T20:45:41.405281707Z phc2sys[357148.840]: [ptp4l.0.config] CLOCK_REALTIME phc offset 18 s2 freq -10081 delay 473 +2023-09-12T20:45:41.467858285Z phc2sys[357148.903]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10088 delay 502 +2023-09-12T20:45:41.530437326Z phc2sys[357148.965]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10089 delay 497 +2023-09-12T20:45:41.593091860Z phc2sys[357149.028]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10092 delay 502 +2023-09-12T20:45:41.655648901Z phc2sys[357149.090]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10093 delay 502 +2023-09-12T20:45:41.718239286Z phc2sys[357149.153]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10090 delay 496 +2023-09-12T20:45:41.780806944Z phc2sys[357149.216]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10093 delay 503 +2023-09-12T20:45:41.843377325Z phc2sys[357149.278]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10091 delay 503 +2023-09-12T20:45:41.905968938Z phc2sys[357149.341]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10090 delay 511 +2023-09-12T20:45:41.968587830Z phc2sys[357149.403]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10090 delay 515 +2023-09-12T20:45:42.000063180Z ts2phc[357149.435]: [ts2phc.0.config] nmea delay: 108641588 ns +2023-09-12T20:45:42.000063180Z ts2phc[357149.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551579.000000000 corr 0 src 1694551579.891380473 diff 0 +2023-09-12T20:45:42.000097728Z ts2phc[357149.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:42.001216077Z I0912 20:45:42.001197 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:42.031147596Z phc2sys[357149.466]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10088 delay 503 +2023-09-12T20:45:42.093730262Z phc2sys[357149.529]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10090 delay 502 +2023-09-12T20:45:42.138904956Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GNRMC,204542.00,A,4233.01594,N,07112.87872,W,0.016,,120923,,,A,V +2023-09-12T20:45:42.139165267Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GNGGA,204542.00,4233.01594,N,07112.87872,W,1,05,1.98,59.8,M,-33.0,M,, +2023-09-12T20:45:42.139165267Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.77,1 +2023-09-12T20:45:42.139184643Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.77,5 +2023-09-12T20:45:42.139184643Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,27,12,33,066,22,21,20,287,19,1 +2023-09-12T20:45:42.139184643Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,19,24,09,056,16,25,45,120,22,28,50,237,23,1 +2023-09-12T20:45:42.139203048Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,231,21,32,69,326,25,1 +2023-09-12T20:45:42.139311621Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GNGST,204542.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:42.139357944Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GNZDA,204542.00,12,09,2023,00,00 +2023-09-12T20:45:42.139481095Z ts2phc[357149.574]: [ts2phc.0.config] nmea sentence: GNGBS,204542.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:42.144600227Z gnss[1694551542]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:42.156305653Z phc2sys[357149.591]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10090 delay 502 +2023-09-12T20:45:42.171006844Z I0912 20:45:42.170978 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:42.171057565Z I0912 20:45:42.171039 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:42.171100194Z I0912 20:45:42.171081 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:42.176086918Z dpll[1694551542]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -4 phase_status 3 s2 +2023-09-12T20:45:42.218881802Z phc2sys[357149.654]: [ptp4l.0.config] CLOCK_REALTIME phc offset 11 s2 freq -10079 delay 473 +2023-09-12T20:45:42.281476551Z phc2sys[357149.716]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10093 delay 501 +2023-09-12T20:45:42.344078353Z phc2sys[357149.779]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10094 delay 509 +2023-09-12T20:45:42.406646467Z phc2sys[357149.841]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10092 delay 502 +2023-09-12T20:45:42.469219902Z phc2sys[357149.904]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10093 delay 504 +2023-09-12T20:45:42.531826409Z phc2sys[357149.967]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10097 delay 501 +2023-09-12T20:45:42.594404176Z phc2sys[357150.029]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10098 delay 502 +2023-09-12T20:45:42.657025073Z phc2sys[357150.092]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10097 delay 503 +2023-09-12T20:45:42.719561696Z phc2sys[357150.154]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10101 delay 501 +2023-09-12T20:45:42.782164102Z phc2sys[357150.217]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10099 delay 502 +2023-09-12T20:45:42.844766366Z phc2sys[357150.280]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10104 delay 501 +2023-09-12T20:45:42.907374116Z phc2sys[357150.342]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10100 delay 506 +2023-09-12T20:45:42.972031615Z phc2sys[357150.405]: [ptp4l.0.config] CLOCK_REALTIME phc offset -9 s2 freq -10109 delay 513 +2023-09-12T20:45:43.000116184Z ts2phc[357150.435]: [ts2phc.0.config] nmea delay: 138856930 ns +2023-09-12T20:45:43.000260947Z ts2phc[357150.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551580.000000000 corr 0 src 1694551580.861170530 diff 0 +2023-09-12T20:45:43.000260947Z ts2phc[357150.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:43.007439273Z I0912 20:45:43.007336 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:43.032534840Z phc2sys[357150.467]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10105 delay 497 +2023-09-12T20:45:43.095206654Z phc2sys[357150.530]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10107 delay 506 +2023-09-12T20:45:43.157763642Z phc2sys[357150.593]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10104 delay 507 +2023-09-12T20:45:43.169087775Z ts2phc[357150.603]: [ts2phc.0.config] nmea sentence: GNRMC,204543.00,A,4233.01594,N,07112.87873,W,0.016,,120923,,,A,V +2023-09-12T20:45:43.169154944Z ts2phc[357150.604]: [ts2phc.0.config] nmea sentence: GNGGA,204543.00,4233.01594,N,07112.87873,W,1,05,1.98,59.7,M,-33.0,M,, +2023-09-12T20:45:43.169184594Z ts2phc[357150.604]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.77,1 +2023-09-12T20:45:43.169209036Z ts2phc[357150.604]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.77,5 +2023-09-12T20:45:43.169241291Z ts2phc[357150.604]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,27,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:43.169329543Z ts2phc[357150.604]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,17,25,45,120,22,28,50,237,23,1 +2023-09-12T20:45:43.169384531Z ts2phc[357150.604]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,21,32,69,326,25,1 +2023-09-12T20:45:43.169384531Z ts2phc[357150.604]: [ts2phc.0.config] nmea sentence: GNGST,204543.00,40,14,11,122,4.8,5.5,11 +2023-09-12T20:45:43.169384531Z ts2phc[357150.604]: [ts2phc.0.config] nmea sentence: GNZDA,204543.00,12,09,2023,00,00 +2023-09-12T20:45:43.169384531Z ts2phc[357150.604]: [ts2phc.0.config] nmea sentence: GNGBS,204543.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:43.171374867Z I0912 20:45:43.171355 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:43.171374867Z I0912 20:45:43.171370 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:43.171407841Z I0912 20:45:43.171377 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:43.172451450Z gnss[1694551543]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:43.172474223Z dpll[1694551543]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 3 phase_status 3 s2 +2023-09-12T20:45:43.220334415Z phc2sys[357150.655]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10108 delay 509 +2023-09-12T20:45:43.282922300Z phc2sys[357150.718]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10110 delay 503 +2023-09-12T20:45:43.345498545Z phc2sys[357150.780]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10107 delay 501 +2023-09-12T20:45:43.408073203Z phc2sys[357150.843]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10109 delay 502 +2023-09-12T20:45:43.470651484Z phc2sys[357150.905]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10108 delay 501 +2023-09-12T20:45:43.533231275Z phc2sys[357150.968]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10106 delay 501 +2023-09-12T20:45:43.595922789Z phc2sys[357151.031]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10101 delay 511 +2023-09-12T20:45:43.658542424Z phc2sys[357151.093]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10098 delay 509 +2023-09-12T20:45:43.721114074Z phc2sys[357151.156]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10098 delay 501 +2023-09-12T20:45:43.783673467Z phc2sys[357151.218]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10095 delay 504 +2023-09-12T20:45:43.846267783Z phc2sys[357151.281]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10093 delay 499 +2023-09-12T20:45:43.908851774Z phc2sys[357151.344]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10092 delay 503 +2023-09-12T20:45:43.971424124Z phc2sys[357151.406]: [ptp4l.0.config] CLOCK_REALTIME phc offset 9 s2 freq -10087 delay 502 +2023-09-12T20:45:44.000067116Z ts2phc[357151.435]: [ts2phc.0.config] nmea delay: 168422384 ns +2023-09-12T20:45:44.000097247Z ts2phc[357151.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551581.000000000 corr 0 src 1694551581.831600433 diff 0 +2023-09-12T20:45:44.000097247Z ts2phc[357151.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:44.003277388Z I0912 20:45:44.003259 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:44.033998262Z phc2sys[357151.469]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10088 delay 502 +2023-09-12T20:45:44.096582101Z phc2sys[357151.531]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10089 delay 506 +2023-09-12T20:45:44.121910169Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GNRMC,204544.00,A,4233.01594,N,07112.87874,W,0.016,,120923,,,A,V +2023-09-12T20:45:44.122530062Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GNGGA,204544.00,4233.01594,N,07112.87874,W,1,05,1.98,59.7,M,-33.0,M,, +2023-09-12T20:45:44.122530062Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.77,1 +2023-09-12T20:45:44.122530062Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.77,5 +2023-09-12T20:45:44.122530062Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,27,12,33,066,22,21,20,287,19,1 +2023-09-12T20:45:44.122562059Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,16,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:44.122562059Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,25,1 +2023-09-12T20:45:44.122562059Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GNGST,204544.00,40,14,11,122,4.8,5.5,11 +2023-09-12T20:45:44.122562059Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GNZDA,204544.00,12,09,2023,00,00 +2023-09-12T20:45:44.122562059Z ts2phc[357151.557]: [ts2phc.0.config] nmea sentence: GNGBS,204544.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:44.126658763Z gnss[1694551544]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:44.159200390Z phc2sys[357151.594]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10084 delay 503 +2023-09-12T20:45:44.171805105Z I0912 20:45:44.171782 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:44.171805105Z I0912 20:45:44.171800 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:44.171831938Z I0912 20:45:44.171806 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:44.177931324Z dpll[1694551544]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 3 phase_status 3 s2 +2023-09-12T20:45:44.221764907Z phc2sys[357151.657]: [ptp4l.0.config] CLOCK_REALTIME phc offset 8 s2 freq -10081 delay 503 +2023-09-12T20:45:44.284354322Z phc2sys[357151.719]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10083 delay 503 +2023-09-12T20:45:44.346939861Z phc2sys[357151.782]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10085 delay 503 +2023-09-12T20:45:44.409511541Z phc2sys[357151.844]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10087 delay 503 +2023-09-12T20:45:44.472083211Z phc2sys[357151.907]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10084 delay 503 +2023-09-12T20:45:44.534755582Z phc2sys[357151.969]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10086 delay 509 +2023-09-12T20:45:44.597983121Z phc2sys[357152.032]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10089 delay 508 +2023-09-12T20:45:44.659912529Z phc2sys[357152.095]: [ptp4l.0.config] CLOCK_REALTIME phc offset -16 s2 freq -10103 delay 483 +2023-09-12T20:45:44.722537002Z phc2sys[357152.157]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10096 delay 511 +2023-09-12T20:45:44.785133731Z phc2sys[357152.220]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10093 delay 511 +2023-09-12T20:45:44.847737907Z phc2sys[357152.283]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10093 delay 500 +2023-09-12T20:45:44.910337573Z phc2sys[357152.345]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10097 delay 502 +2023-09-12T20:45:44.972926650Z phc2sys[357152.408]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10100 delay 503 +2023-09-12T20:45:45.000118567Z ts2phc[357152.435]: [ts2phc.0.config] nmea delay: 121817530 ns +2023-09-12T20:45:45.000118567Z ts2phc[357152.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551582.000000000 corr 0 src 1694551582.878206386 diff 0 +2023-09-12T20:45:45.000118567Z ts2phc[357152.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:45.010359974Z I0912 20:45:45.010336 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:45.035505752Z phc2sys[357152.470]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10094 delay 503 +2023-09-12T20:45:45.098098114Z phc2sys[357152.533]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10093 delay 504 +2023-09-12T20:45:45.114893434Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GNRMC,204545.00,A,4233.01594,N,07112.87874,W,0.016,,120923,,,A,V +2023-09-12T20:45:45.115487306Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GNGGA,204545.00,4233.01594,N,07112.87874,W,1,05,1.98,59.6,M,-33.0,M,, +2023-09-12T20:45:45.115487306Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.25,1.98,3.77,1 +2023-09-12T20:45:45.115487306Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.25,1.98,3.77,5 +2023-09-12T20:45:45.115487306Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,26,12,33,066,21,21,20,287,19,1 +2023-09-12T20:45:45.115512480Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,16,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:45.115512480Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:45.115512480Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GNGST,204545.00,42,14,11,122,4.8,5.5,11 +2023-09-12T20:45:45.115512480Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GNZDA,204545.00,12,09,2023,00,00 +2023-09-12T20:45:45.115512480Z ts2phc[357152.550]: [ts2phc.0.config] nmea sentence: GNGBS,204545.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:45.123814891Z gnss[1694551545]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:45.160676035Z phc2sys[357152.595]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10094 delay 503 +2023-09-12T20:45:45.171202632Z I0912 20:45:45.171181 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:45.171202632Z I0912 20:45:45.171195 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:45.171228280Z I0912 20:45:45.171201 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:45.175333466Z dpll[1694551545]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 0 phase_status 3 s2 +2023-09-12T20:45:45.223259747Z phc2sys[357152.658]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10091 delay 500 +2023-09-12T20:45:45.285844945Z phc2sys[357152.721]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10096 delay 502 +2023-09-12T20:45:45.348409764Z phc2sys[357152.783]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10095 delay 503 +2023-09-12T20:45:45.411005316Z phc2sys[357152.846]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10100 delay 503 +2023-09-12T20:45:45.473582376Z phc2sys[357152.908]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10095 delay 503 +2023-09-12T20:45:45.536161854Z phc2sys[357152.971]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10097 delay 503 +2023-09-12T20:45:45.598792088Z phc2sys[357153.034]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10099 delay 508 +2023-09-12T20:45:45.661460639Z phc2sys[357153.096]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10097 delay 501 +2023-09-12T20:45:45.724001683Z phc2sys[357153.159]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10098 delay 510 +2023-09-12T20:45:45.786589285Z phc2sys[357153.221]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10096 delay 503 +2023-09-12T20:45:45.849167658Z phc2sys[357153.284]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10099 delay 503 +2023-09-12T20:45:45.911872099Z phc2sys[357153.347]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10101 delay 505 +2023-09-12T20:45:45.974390586Z phc2sys[357153.409]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10094 delay 503 +2023-09-12T20:45:46.000077318Z ts2phc[357153.435]: [ts2phc.0.config] nmea delay: 114836171 ns +2023-09-12T20:45:46.000110973Z ts2phc[357153.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551583.000000000 corr 0 src 1694551583.885187285 diff 0 +2023-09-12T20:45:46.000121713Z ts2phc[357153.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:46.009470926Z I0912 20:45:46.009447 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:46.036960559Z phc2sys[357153.472]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10096 delay 503 +2023-09-12T20:45:46.099547538Z phc2sys[357153.534]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10092 delay 498 +2023-09-12T20:45:46.116927061Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GNRMC,204546.00,A,4233.01594,N,07112.87876,W,0.016,,120923,,,A,V +2023-09-12T20:45:46.117393443Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GNGGA,204546.00,4233.01594,N,07112.87876,W,1,05,1.98,59.6,M,-33.0,M,, +2023-09-12T20:45:46.117393443Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:46.117393443Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:46.117393443Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,27,12,33,066,22,21,20,287,19,1 +2023-09-12T20:45:46.117424538Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,16,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:46.117424538Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:46.117424538Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GNGST,204546.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:46.117424538Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GNZDA,204546.00,12,09,2023,00,00 +2023-09-12T20:45:46.117542070Z ts2phc[357153.552]: [ts2phc.0.config] nmea sentence: GNGBS,204546.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:46.122753428Z gnss[1694551546]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:46.162126932Z phc2sys[357153.597]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10089 delay 502 +2023-09-12T20:45:46.171591981Z I0912 20:45:46.171570 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:46.171591981Z I0912 20:45:46.171585 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:46.171619667Z I0912 20:45:46.171592 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:46.174732642Z dpll[1694551546]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 0 phase_status 3 s2 +2023-09-12T20:45:46.224733947Z phc2sys[357153.659]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10094 delay 502 +2023-09-12T20:45:46.287299364Z phc2sys[357153.722]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10096 delay 503 +2023-09-12T20:45:46.349995685Z phc2sys[357153.785]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10089 delay 503 +2023-09-12T20:45:46.412462052Z phc2sys[357153.847]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10091 delay 503 +2023-09-12T20:45:46.475040478Z phc2sys[357153.910]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10092 delay 501 +2023-09-12T20:45:46.537695502Z phc2sys[357153.972]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10094 delay 508 +2023-09-12T20:45:46.600248112Z phc2sys[357154.035]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10091 delay 495 +2023-09-12T20:45:46.662822586Z phc2sys[357154.098]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10092 delay 503 +2023-09-12T20:45:46.725419964Z phc2sys[357154.160]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10088 delay 498 +2023-09-12T20:45:46.788004022Z phc2sys[357154.223]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10090 delay 501 +2023-09-12T20:45:46.850605600Z phc2sys[357154.285]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10097 delay 512 +2023-09-12T20:45:46.913201651Z phc2sys[357154.348]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10095 delay 500 +2023-09-12T20:45:46.975783386Z phc2sys[357154.411]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10093 delay 503 +2023-09-12T20:45:47.000064114Z ts2phc[357154.435]: [ts2phc.0.config] nmea delay: 116873321 ns +2023-09-12T20:45:47.000064114Z ts2phc[357154.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551584.000000000 corr 0 src 1694551584.883148424 diff 0 +2023-09-12T20:45:47.000095782Z ts2phc[357154.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:47.006303183Z I0912 20:45:47.006285 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:47.038375746Z phc2sys[357154.473]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10092 delay 503 +2023-09-12T20:45:47.100955003Z phc2sys[357154.536]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10090 delay 502 +2023-09-12T20:45:47.110014657Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GNRMC,204547.00,A,4233.01593,N,07112.87878,W,0.016,,120923,,,A,V +2023-09-12T20:45:47.110625041Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GNGGA,204547.00,4233.01593,N,07112.87878,W,1,05,1.98,59.5,M,-33.0,M,, +2023-09-12T20:45:47.110625041Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:47.110625041Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:47.110625041Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,27,12,33,066,22,21,20,287,19,1 +2023-09-12T20:45:47.110625041Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,16,25,45,120,22,28,50,237,24,1 +2023-09-12T20:45:47.110625041Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,21,32,69,327,24,1 +2023-09-12T20:45:47.110625041Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GNGST,204547.00,40,14,11,122,4.8,5.5,11 +2023-09-12T20:45:47.110625041Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GNZDA,204547.00,12,09,2023,00,00 +2023-09-12T20:45:47.110656620Z ts2phc[357154.545]: [ts2phc.0.config] nmea sentence: GNGBS,204547.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:47.119987064Z gnss[1694551547]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:47.163568885Z phc2sys[357154.598]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10095 delay 505 +2023-09-12T20:45:47.171135783Z I0912 20:45:47.171116 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:47.171135783Z I0912 20:45:47.171129 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:47.171163501Z I0912 20:45:47.171134 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:47.181264902Z dpll[1694551547]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -2 phase_status 3 s2 +2023-09-12T20:45:47.226121792Z phc2sys[357154.661]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10094 delay 502 +2023-09-12T20:45:47.288743902Z phc2sys[357154.724]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10094 delay 502 +2023-09-12T20:45:47.351301903Z phc2sys[357154.786]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10094 delay 503 +2023-09-12T20:45:47.413881157Z phc2sys[357154.849]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10097 delay 502 +2023-09-12T20:45:47.476453658Z phc2sys[357154.911]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10095 delay 503 +2023-09-12T20:45:47.539039689Z phc2sys[357154.974]: [ptp4l.0.config] CLOCK_REALTIME phc offset -8 s2 freq -10103 delay 503 +2023-09-12T20:45:47.601623959Z phc2sys[357155.036]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10103 delay 506 +2023-09-12T20:45:47.664308169Z phc2sys[357155.099]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10102 delay 508 +2023-09-12T20:45:47.726826387Z phc2sys[357155.162]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10103 delay 502 +2023-09-12T20:45:47.789406282Z phc2sys[357155.224]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10102 delay 503 +2023-09-12T20:45:47.852003445Z phc2sys[357155.287]: [ptp4l.0.config] CLOCK_REALTIME phc offset -8 s2 freq -10109 delay 503 +2023-09-12T20:45:47.914584603Z phc2sys[357155.349]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10107 delay 502 +2023-09-12T20:45:47.977169023Z phc2sys[357155.412]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10105 delay 502 +2023-09-12T20:45:48.000063778Z ts2phc[357155.435]: [ts2phc.0.config] nmea delay: 109957909 ns +2023-09-12T20:45:48.000063778Z ts2phc[357155.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551585.000000000 corr 0 src 1694551585.890064841 diff 0 +2023-09-12T20:45:48.000096516Z ts2phc[357155.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:48.002233246Z I0912 20:45:48.002215 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:48.039754479Z phc2sys[357155.475]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10109 delay 502 +2023-09-12T20:45:48.102332753Z phc2sys[357155.537]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10106 delay 503 +2023-09-12T20:45:48.121874478Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GNRMC,204548.00,A,4233.01593,N,07112.87880,W,0.016,,120923,,,A,V +2023-09-12T20:45:48.122540400Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GNGGA,204548.00,4233.01593,N,07112.87880,W,1,05,1.98,59.5,M,-33.0,M,, +2023-09-12T20:45:48.122589260Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:48.122622001Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:48.122622001Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,26,12,33,066,22,21,20,287,20,1 +2023-09-12T20:45:48.122622001Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,16,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:48.122655457Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,21,32,69,327,24,1 +2023-09-12T20:45:48.122655457Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GNGST,204548.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:48.122655457Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GNZDA,204548.00,12,09,2023,00,00 +2023-09-12T20:45:48.122655457Z ts2phc[357155.557]: [ts2phc.0.config] nmea sentence: GNGBS,204548.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:48.124705797Z gnss[1694551548]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:48.164911442Z phc2sys[357155.600]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10105 delay 503 +2023-09-12T20:45:48.171290311Z I0912 20:45:48.171269 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:48.171290311Z I0912 20:45:48.171284 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:48.171316303Z I0912 20:45:48.171289 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:48.176426873Z dpll[1694551548]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -3 phase_status 3 s2 +2023-09-12T20:45:48.227493856Z phc2sys[357155.662]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10105 delay 503 +2023-09-12T20:45:48.290068203Z phc2sys[357155.725]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10102 delay 502 +2023-09-12T20:45:48.352648600Z phc2sys[357155.787]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10107 delay 503 +2023-09-12T20:45:48.415224488Z phc2sys[357155.850]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10106 delay 508 +2023-09-12T20:45:48.477815410Z phc2sys[357155.913]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10102 delay 503 +2023-09-12T20:45:48.540399210Z phc2sys[357155.975]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10106 delay 504 +2023-09-12T20:45:48.602990302Z phc2sys[357156.038]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10102 delay 504 +2023-09-12T20:45:48.665567227Z phc2sys[357156.100]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10102 delay 508 +2023-09-12T20:45:48.728145841Z phc2sys[357156.163]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10106 delay 502 +2023-09-12T20:45:48.790731949Z phc2sys[357156.226]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10101 delay 503 +2023-09-12T20:45:48.853292064Z phc2sys[357156.288]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10097 delay 503 +2023-09-12T20:45:48.915866837Z phc2sys[357156.351]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10103 delay 502 +2023-09-12T20:45:48.978449589Z phc2sys[357156.413]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10097 delay 502 +2023-09-12T20:45:49.000100387Z ts2phc[357156.435]: [ts2phc.0.config] nmea delay: 121820476 ns +2023-09-12T20:45:49.000139771Z ts2phc[357156.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551586.000000000 corr 0 src 1694551586.878205556 diff 0 +2023-09-12T20:45:49.000139771Z ts2phc[357156.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:49.007341840Z I0912 20:45:49.007323 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:49.041053052Z phc2sys[357156.476]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10098 delay 508 +2023-09-12T20:45:49.103662061Z phc2sys[357156.538]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10099 delay 499 +2023-09-12T20:45:49.112865990Z ts2phc[357156.547]: [ts2phc.0.config] nmea sentence: GNRMC,204549.00,A,4233.01592,N,07112.87882,W,0.016,,120923,,,A,V +2023-09-12T20:45:49.113143292Z ts2phc[357156.548]: [ts2phc.0.config] nmea sentence: GNGGA,204549.00,4233.01592,N,07112.87882,W,1,05,1.98,59.4,M,-33.0,M,, +2023-09-12T20:45:49.113208032Z ts2phc[357156.548]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:49.113239864Z ts2phc[357156.548]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:49.113264861Z ts2phc[357156.548]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,26,12,33,066,22,21,20,287,19,1 +2023-09-12T20:45:49.113303450Z ts2phc[357156.548]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,15,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:49.113332226Z ts2phc[357156.548]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,21,32,69,327,24,1 +2023-09-12T20:45:49.113332226Z ts2phc[357156.548]: [ts2phc.0.config] nmea sentence: GNGST,204549.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:49.113332226Z ts2phc[357156.548]: [ts2phc.0.config] nmea sentence: GNZDA,204549.00,12,09,2023,00,00 +2023-09-12T20:45:49.113332226Z ts2phc[357156.548]: [ts2phc.0.config] nmea sentence: GNGBS,204549.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:49.120164779Z gnss[1694551549]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:49.166224096Z phc2sys[357156.601]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10100 delay 502 +2023-09-12T20:45:49.171627998Z I0912 20:45:49.171606 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:49.171627998Z I0912 20:45:49.171623 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:49.171673735Z I0912 20:45:49.171630 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:49.181768932Z dpll[1694551549]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 4 phase_status 3 s2 +2023-09-12T20:45:49.228828168Z phc2sys[357156.664]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10103 delay 503 +2023-09-12T20:45:49.291501772Z phc2sys[357156.726]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10099 delay 507 +2023-09-12T20:45:49.354062181Z phc2sys[357156.789]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10104 delay 504 +2023-09-12T20:45:49.416663471Z phc2sys[357156.851]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10101 delay 497 +2023-09-12T20:45:49.479252968Z phc2sys[357156.914]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10102 delay 502 +2023-09-12T20:45:49.541828791Z phc2sys[357156.977]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10098 delay 508 +2023-09-12T20:45:49.607725569Z phc2sys[357157.039]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10105 delay 507 +2023-09-12T20:45:49.667077385Z phc2sys[357157.102]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10100 delay 503 +2023-09-12T20:45:49.729641789Z phc2sys[357157.164]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10098 delay 503 +2023-09-12T20:45:49.792219135Z phc2sys[357157.227]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10096 delay 502 +2023-09-12T20:45:49.854821619Z phc2sys[357157.290]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10100 delay 509 +2023-09-12T20:45:49.917406528Z phc2sys[357157.352]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10099 delay 503 +2023-09-12T20:45:49.980001611Z phc2sys[357157.415]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10101 delay 503 +2023-09-12T20:45:50.000062986Z ts2phc[357157.435]: [ts2phc.0.config] nmea delay: 112404091 ns +2023-09-12T20:45:50.000062986Z ts2phc[357157.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551587.000000000 corr 0 src 1694551587.887619890 diff 0 +2023-09-12T20:45:50.000062986Z ts2phc[357157.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:50.008266938Z I0912 20:45:50.008248 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:50.042579131Z phc2sys[357157.477]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10101 delay 504 +2023-09-12T20:45:50.105154664Z phc2sys[357157.540]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10101 delay 503 +2023-09-12T20:45:50.121851730Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GNRMC,204550.00,A,4233.01591,N,07112.87883,W,0.016,,120923,,,A,V +2023-09-12T20:45:50.122394453Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GNGGA,204550.00,4233.01591,N,07112.87883,W,1,05,1.98,59.4,M,-33.0,M,, +2023-09-12T20:45:50.122394453Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:50.122394453Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:50.122394453Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,27,12,33,066,22,21,20,287,19,1 +2023-09-12T20:45:50.122394453Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,16,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:50.122394453Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:50.122394453Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GNGST,204550.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:50.122454864Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GNZDA,204550.00,12,09,2023,00,00 +2023-09-12T20:45:50.122545834Z ts2phc[357157.557]: [ts2phc.0.config] nmea sentence: GNGBS,204550.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:50.130731327Z gnss[1694551550]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:50.167752851Z phc2sys[357157.603]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10100 delay 497 +2023-09-12T20:45:50.171544501Z I0912 20:45:50.171507 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:50.172387378Z I0912 20:45:50.172367 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:50.173240373Z I0912 20:45:50.172919 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:50.182510255Z dpll[1694551550]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 0 phase_status 3 s2 +2023-09-12T20:45:50.230329130Z phc2sys[357157.665]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10103 delay 503 +2023-09-12T20:45:50.292925410Z phc2sys[357157.728]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10104 delay 503 +2023-09-12T20:45:50.355498750Z phc2sys[357157.790]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10100 delay 503 +2023-09-12T20:45:50.418082226Z phc2sys[357157.853]: [ptp4l.0.config] CLOCK_REALTIME phc offset 22 s2 freq -10080 delay 473 +2023-09-12T20:45:50.480660884Z phc2sys[357157.915]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10096 delay 503 +2023-09-12T20:45:50.543252692Z phc2sys[357157.978]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10094 delay 502 +2023-09-12T20:45:50.605935922Z phc2sys[357158.041]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10093 delay 508 +2023-09-12T20:45:50.668413764Z phc2sys[357158.103]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10089 delay 502 +2023-09-12T20:45:50.731001171Z phc2sys[357158.166]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10096 delay 503 +2023-09-12T20:45:50.793589761Z phc2sys[357158.228]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10094 delay 503 +2023-09-12T20:45:50.856185896Z phc2sys[357158.291]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10097 delay 516 +2023-09-12T20:45:50.918764847Z phc2sys[357158.354]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10090 delay 502 +2023-09-12T20:45:50.981334928Z phc2sys[357158.416]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10092 delay 502 +2023-09-12T20:45:51.000076517Z ts2phc[357158.435]: [ts2phc.0.config] nmea delay: 121795513 ns +2023-09-12T20:45:51.000135371Z ts2phc[357158.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551588.000000000 corr 0 src 1694551588.878229417 diff 0 +2023-09-12T20:45:51.000194720Z ts2phc[357158.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:51.003351258Z I0912 20:45:51.003333 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:51.043467141Z ts2phc[357158.478]: [ts2phc.0.config] nmea sentence: GNRMC,204551.00,A,4233.01591,N,07112.87883,W,0.016,,120923,,,A,V +2023-09-12T20:45:51.043967265Z phc2sys[357158.479]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10093 delay 503 +2023-09-12T20:45:51.106506744Z phc2sys[357158.541]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10090 delay 502 +2023-09-12T20:45:51.169114060Z phc2sys[357158.604]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10090 delay 503 +2023-09-12T20:45:51.171575417Z I0912 20:45:51.171537 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:51.171602292Z I0912 20:45:51.171571 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:51.171602292Z I0912 20:45:51.171586 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:51.178694575Z dpll[1694551551]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -2 phase_status 3 s2 +2023-09-12T20:45:51.211445030Z ts2phc[357158.646]: [ts2phc.0.config] nmea sentence: GNGGA,204551.00,4233.01591,N,07112.87883,W,1,05,1.98,59.3,M,-33.0,M,, +2023-09-12T20:45:51.211445030Z ts2phc[357158.646]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:51.211445030Z ts2phc[357158.646]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:51.211502659Z ts2phc[357158.646]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,22,10,63,173,27,12,33,066,21,21,20,287,18,1 +2023-09-12T20:45:51.211502659Z ts2phc[357158.646]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,21,24,09,056,16,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:51.211709047Z ts2phc[357158.646]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:51.211731496Z ts2phc[357158.647]: [ts2phc.0.config] nmea sentence: GNGST,204551.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:51.211731496Z ts2phc[357158.647]: [ts2phc.0.config] nmea sentence: GNZDA,204551.00,12,09,2023,00,00 +2023-09-12T20:45:51.211916444Z ts2phc[357158.647]: [ts2phc.0.config] nmea sentence: GNGBS,204551.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:51.220063027Z gnss[1694551551]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:51.231693986Z phc2sys[357158.666]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10094 delay 503 +2023-09-12T20:45:51.294320671Z phc2sys[357158.729]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10092 delay 504 +2023-09-12T20:45:51.356879270Z phc2sys[357158.792]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10090 delay 504 +2023-09-12T20:45:51.419454248Z phc2sys[357158.854]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10092 delay 503 +2023-09-12T20:45:51.482033838Z phc2sys[357158.917]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10091 delay 503 +2023-09-12T20:45:51.544624953Z phc2sys[357158.979]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10093 delay 511 +2023-09-12T20:45:51.607255549Z phc2sys[357159.042]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10093 delay 514 +2023-09-12T20:45:51.669849712Z phc2sys[357159.105]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10094 delay 503 +2023-09-12T20:45:51.732440674Z phc2sys[357159.167]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10092 delay 503 +2023-09-12T20:45:51.795034780Z phc2sys[357159.230]: [ptp4l.0.config] CLOCK_REALTIME phc offset -12 s2 freq -10105 delay 515 +2023-09-12T20:45:51.857629391Z phc2sys[357159.292]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10100 delay 502 +2023-09-12T20:45:51.920198990Z phc2sys[357159.355]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10103 delay 501 +2023-09-12T20:45:51.982810512Z phc2sys[357159.418]: [ptp4l.0.config] CLOCK_REALTIME phc offset -7 s2 freq -10106 delay 503 +2023-09-12T20:45:52.000084168Z ts2phc[357159.435]: [ts2phc.0.config] nmea delay: 43415441 ns +2023-09-12T20:45:52.000140568Z ts2phc[357159.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551589.000000000 corr 0 src 1694551589.956607315 diff 0 +2023-09-12T20:45:52.000168271Z ts2phc[357159.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:52.000287782Z I0912 20:45:52.000267 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:52.045392079Z phc2sys[357159.480]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10107 delay 503 +2023-09-12T20:45:52.068887138Z I0912 20:45:52.068857 161357 main.go:140] ticker pull +2023-09-12T20:45:52.107985718Z phc2sys[357159.543]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10103 delay 513 +2023-09-12T20:45:52.121907579Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GNRMC,204552.00,A,4233.01590,N,07112.87883,W,0.016,,120923,,,A,V +2023-09-12T20:45:52.122366018Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GNGGA,204552.00,4233.01590,N,07112.87883,W,1,05,1.98,59.3,M,-33.0,M,, +2023-09-12T20:45:52.122406859Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:52.122475281Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:52.122625653Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:52.122625653Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,21,24,09,056,15,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:52.122625653Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:52.122625653Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GNGST,204552.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:52.122625653Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GNZDA,204552.00,12,09,2023,00,00 +2023-09-12T20:45:52.122625653Z ts2phc[357159.557]: [ts2phc.0.config] nmea sentence: GNGBS,204552.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:52.123623422Z gnss[1694551552]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:52.170592703Z phc2sys[357159.605]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10103 delay 503 +2023-09-12T20:45:52.170898248Z I0912 20:45:52.170860 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:52.170946225Z I0912 20:45:52.170932 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:52.170974736Z I0912 20:45:52.170963 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:52.174984489Z dpll[1694551552]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -4 phase_status 3 s2 +2023-09-12T20:45:52.233453026Z phc2sys[357159.668]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10108 delay 509 +2023-09-12T20:45:52.295996690Z phc2sys[357159.731]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10103 delay 508 +2023-09-12T20:45:52.358631536Z phc2sys[357159.793]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10104 delay 508 +2023-09-12T20:45:52.421191911Z phc2sys[357159.856]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10104 delay 502 +2023-09-12T20:45:52.483845942Z phc2sys[357159.919]: [ptp4l.0.config] CLOCK_REALTIME phc offset 16 s2 freq -10088 delay 423 +2023-09-12T20:45:52.546382678Z phc2sys[357159.981]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10099 delay 503 +2023-09-12T20:45:52.608967247Z phc2sys[357160.044]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10098 delay 492 +2023-09-12T20:45:52.671618669Z phc2sys[357160.106]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10094 delay 503 +2023-09-12T20:45:52.734185149Z phc2sys[357160.169]: [ptp4l.0.config] CLOCK_REALTIME phc offset 19 s2 freq -10078 delay 457 +2023-09-12T20:45:52.796779988Z phc2sys[357160.232]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10092 delay 498 +2023-09-12T20:45:52.859373942Z phc2sys[357160.294]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10090 delay 502 +2023-09-12T20:45:52.921957891Z phc2sys[357160.357]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10090 delay 502 +2023-09-12T20:45:52.984574823Z phc2sys[357160.419]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10097 delay 503 +2023-09-12T20:45:53.000084378Z ts2phc[357160.435]: [ts2phc.0.config] nmea delay: 121846077 ns +2023-09-12T20:45:53.000112512Z ts2phc[357160.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551590.000000000 corr 0 src 1694551590.878183172 diff 0 +2023-09-12T20:45:53.000112512Z ts2phc[357160.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:53.005295241Z I0912 20:45:53.005276 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:53.047164381Z phc2sys[357160.482]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10095 delay 499 +2023-09-12T20:45:53.109779230Z phc2sys[357160.545]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10094 delay 503 +2023-09-12T20:45:53.122002735Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GNRMC,204553.00,A,4233.01589,N,07112.87882,W,0.016,,120923,,,A,V +2023-09-12T20:45:53.122651379Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GNGGA,204553.00,4233.01589,N,07112.87882,W,1,05,1.98,59.3,M,-33.0,M,, +2023-09-12T20:45:53.122651379Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:53.122651379Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:53.122651379Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:53.122673797Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,21,24,09,056,15,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:53.122673797Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:53.122673797Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GNGST,204553.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:53.122673797Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GNZDA,204553.00,12,09,2023,00,00 +2023-09-12T20:45:53.122673797Z ts2phc[357160.557]: [ts2phc.0.config] nmea sentence: GNGBS,204553.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:53.128698724Z gnss[1694551553]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:53.170783874Z I0912 20:45:53.170765 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:53.170783874Z I0912 20:45:53.170778 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:53.170819611Z I0912 20:45:53.170784 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:53.172344241Z phc2sys[357160.607]: [ptp4l.0.config] CLOCK_REALTIME phc offset 28 s2 freq -10066 delay 451 +2023-09-12T20:45:53.180608100Z dpll[1694551553]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -4 phase_status 3 s2 +2023-09-12T20:45:53.234941408Z phc2sys[357160.670]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10080 delay 412 +2023-09-12T20:45:53.297507471Z phc2sys[357160.732]: [ptp4l.0.config] CLOCK_REALTIME phc offset 11 s2 freq -10073 delay 423 +2023-09-12T20:45:53.360316132Z phc2sys[357160.795]: [ptp4l.0.config] CLOCK_REALTIME phc offset -11 s2 freq -10091 delay 515 +2023-09-12T20:45:53.422705493Z phc2sys[357160.857]: [ptp4l.0.config] CLOCK_REALTIME phc offset -14 s2 freq -10098 delay 515 +2023-09-12T20:45:53.485317546Z phc2sys[357160.920]: [ptp4l.0.config] CLOCK_REALTIME phc offset 9 s2 freq -10079 delay 414 +2023-09-12T20:45:53.547917020Z phc2sys[357160.983]: [ptp4l.0.config] CLOCK_REALTIME phc offset -10 s2 freq -10095 delay 504 +2023-09-12T20:45:53.610535713Z phc2sys[357161.045]: [ptp4l.0.config] CLOCK_REALTIME phc offset -7 s2 freq -10095 delay 501 +2023-09-12T20:45:53.673136283Z phc2sys[357161.108]: [ptp4l.0.config] CLOCK_REALTIME phc offset -14 s2 freq -10104 delay 503 +2023-09-12T20:45:53.735767049Z phc2sys[357161.171]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10091 delay 457 +2023-09-12T20:45:53.798358061Z phc2sys[357161.233]: [ptp4l.0.config] CLOCK_REALTIME phc offset -13 s2 freq -10107 delay 510 +2023-09-12T20:45:53.860938607Z phc2sys[357161.296]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10090 delay 469 +2023-09-12T20:45:53.923579665Z phc2sys[357161.358]: [ptp4l.0.config] CLOCK_REALTIME phc offset -14 s2 freq -10109 delay 506 +2023-09-12T20:45:53.986104812Z phc2sys[357161.421]: [ptp4l.0.config] CLOCK_REALTIME phc offset -13 s2 freq -10113 delay 499 +2023-09-12T20:45:54.000073887Z ts2phc[357161.435]: [ts2phc.0.config] nmea delay: 121790902 ns +2023-09-12T20:45:54.000106970Z ts2phc[357161.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551591.000000000 corr 0 src 1694551591.878232372 diff 0 +2023-09-12T20:45:54.000106970Z ts2phc[357161.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:54.001239765Z I0912 20:45:54.001221 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:54.048681807Z phc2sys[357161.483]: [ptp4l.0.config] CLOCK_REALTIME phc offset -11 s2 freq -10114 delay 509 +2023-09-12T20:45:54.111258753Z phc2sys[357161.546]: [ptp4l.0.config] CLOCK_REALTIME phc offset -25 s2 freq -10132 delay 471 +2023-09-12T20:45:54.121881466Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GNRMC,204554.00,A,4233.01588,N,07112.87882,W,0.016,,120923,,,A,V +2023-09-12T20:45:54.122682505Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GNGGA,204554.00,4233.01588,N,07112.87882,W,1,05,1.98,59.2,M,-33.0,M,, +2023-09-12T20:45:54.122738140Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:54.122782755Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:54.122815816Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:54.122815816Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,21,24,09,056,14,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:54.122815816Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:54.122815816Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GNGST,204554.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:54.122815816Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GNZDA,204554.00,12,09,2023,00,00 +2023-09-12T20:45:54.122815816Z ts2phc[357161.557]: [ts2phc.0.config] nmea sentence: GNGBS,204554.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:54.124891772Z gnss[1694551554]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:54.170915655Z I0912 20:45:54.170892 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:54.170915655Z I0912 20:45:54.170910 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:54.170943299Z I0912 20:45:54.170918 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:54.173845545Z phc2sys[357161.609]: [ptp4l.0.config] CLOCK_REALTIME phc offset -10 s2 freq -10124 delay 515 +2023-09-12T20:45:54.176066181Z dpll[1694551554]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 1 phase_status 3 s2 +2023-09-12T20:45:54.236434482Z phc2sys[357161.671]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10118 delay 503 +2023-09-12T20:45:54.299054933Z phc2sys[357161.734]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10123 delay 502 +2023-09-12T20:45:54.361626335Z phc2sys[357161.796]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10115 delay 502 +2023-09-12T20:45:54.424203771Z phc2sys[357161.859]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10116 delay 503 +2023-09-12T20:45:54.486775848Z phc2sys[357161.922]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10111 delay 503 +2023-09-12T20:45:54.549358420Z phc2sys[357161.984]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10114 delay 503 +2023-09-12T20:45:54.611918856Z phc2sys[357162.047]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10109 delay 499 +2023-09-12T20:45:54.674493875Z phc2sys[357162.109]: [ptp4l.0.config] CLOCK_REALTIME phc offset 8 s2 freq -10105 delay 503 +2023-09-12T20:45:54.737073597Z phc2sys[357162.172]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10105 delay 500 +2023-09-12T20:45:54.799654298Z phc2sys[357162.234]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10107 delay 503 +2023-09-12T20:45:54.862220152Z phc2sys[357162.297]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10104 delay 501 +2023-09-12T20:45:54.924803353Z phc2sys[357162.360]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10101 delay 510 +2023-09-12T20:45:54.987440609Z phc2sys[357162.422]: [ptp4l.0.config] CLOCK_REALTIME phc offset 8 s2 freq -10097 delay 506 +2023-09-12T20:45:55.000088102Z ts2phc[357162.435]: [ts2phc.0.config] nmea delay: 121831591 ns +2023-09-12T20:45:55.000144757Z ts2phc[357162.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551592.000000000 corr 0 src 1694551592.878195081 diff 0 +2023-09-12T20:45:55.000197576Z ts2phc[357162.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:55.007413153Z I0912 20:45:55.007388 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:55.050025097Z phc2sys[357162.485]: [ptp4l.0.config] CLOCK_REALTIME phc offset 8 s2 freq -10095 delay 500 +2023-09-12T20:45:55.112615688Z phc2sys[357162.547]: [ptp4l.0.config] CLOCK_REALTIME phc offset 7 s2 freq -10093 delay 500 +2023-09-12T20:45:55.116994336Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GNRMC,204555.00,A,4233.01588,N,07112.87881,W,0.015,,120923,,,A,V +2023-09-12T20:45:55.117451620Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GNGGA,204555.00,4233.01588,N,07112.87881,W,1,05,1.98,59.2,M,-33.0,M,, +2023-09-12T20:45:55.117624639Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:55.117624639Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:55.117624639Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:55.117624639Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,21,24,09,056,15,25,45,120,23,28,50,237,24,1 +2023-09-12T20:45:55.117624639Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:55.117624639Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GNGST,204555.00,40,14,11,122,4.8,5.5,11 +2023-09-12T20:45:55.117624639Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GNZDA,204555.00,12,09,2023,00,00 +2023-09-12T20:45:55.117624639Z ts2phc[357162.552]: [ts2phc.0.config] nmea sentence: GNGBS,204555.00,4.8,5.5,10.9,,,,,, +2023-09-12T20:45:55.119739635Z gnss[1694551555]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:55.171070925Z I0912 20:45:55.171038 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:55.171129347Z I0912 20:45:55.171113 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:55.171164956Z I0912 20:45:55.171150 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:55.172112841Z dpll[1694551555]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 0 phase_status 3 s2 +2023-09-12T20:45:55.175249089Z phc2sys[357162.610]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10093 delay 508 +2023-09-12T20:45:55.237826663Z phc2sys[357162.673]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10091 delay 502 +2023-09-12T20:45:55.300420995Z phc2sys[357162.735]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10092 delay 505 +2023-09-12T20:45:55.363014792Z phc2sys[357162.798]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10089 delay 503 +2023-09-12T20:45:55.425585997Z phc2sys[357162.860]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10091 delay 499 +2023-09-12T20:45:55.488176389Z phc2sys[357162.923]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10090 delay 503 +2023-09-12T20:45:55.550788741Z phc2sys[357162.986]: [ptp4l.0.config] CLOCK_REALTIME phc offset -13 s2 freq -10104 delay 493 +2023-09-12T20:45:55.613439504Z phc2sys[357163.048]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10097 delay 516 +2023-09-12T20:45:55.676050538Z phc2sys[357163.111]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10097 delay 506 +2023-09-12T20:45:55.738706168Z phc2sys[357163.173]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10098 delay 515 +2023-09-12T20:45:55.801281124Z phc2sys[357163.236]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10094 delay 503 +2023-09-12T20:45:55.863880901Z phc2sys[357163.299]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10094 delay 503 +2023-09-12T20:45:55.926467007Z phc2sys[357163.361]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10098 delay 502 +2023-09-12T20:45:55.989058670Z phc2sys[357163.424]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10098 delay 503 +2023-09-12T20:45:56.000068240Z ts2phc[357163.435]: [ts2phc.0.config] nmea delay: 116900440 ns +2023-09-12T20:45:56.000068240Z ts2phc[357163.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551593.000000000 corr 0 src 1694551593.883123599 diff 0 +2023-09-12T20:45:56.000100691Z ts2phc[357163.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:56.004284319Z I0912 20:45:56.004265 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:56.051655369Z phc2sys[357163.486]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10096 delay 502 +2023-09-12T20:45:56.114249287Z phc2sys[357163.549]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10095 delay 503 +2023-09-12T20:45:56.114906065Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GNRMC,204556.00,A,4233.01587,N,07112.87880,W,0.015,,120923,,,A,V +2023-09-12T20:45:56.115361703Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GNGGA,204556.00,4233.01587,N,07112.87880,W,1,05,1.98,59.1,M,-33.0,M,, +2023-09-12T20:45:56.115361703Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.98,3.77,1 +2023-09-12T20:45:56.115361703Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.98,3.77,5 +2023-09-12T20:45:56.115361703Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,26,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:56.115361703Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,21,24,09,056,14,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:56.115361703Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:56.115385238Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GNGST,204556.00,41,14,11,122,4.8,5.5,11 +2023-09-12T20:45:56.115385238Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GNZDA,204556.00,12,09,2023,00,00 +2023-09-12T20:45:56.115487737Z ts2phc[357163.550]: [ts2phc.0.config] nmea sentence: GNGBS,204556.00,4.8,5.5,11.0,,,,,, +2023-09-12T20:45:56.117659243Z gnss[1694551556]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:56.170925432Z I0912 20:45:56.170906 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:56.170925432Z I0912 20:45:56.170919 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:56.170975796Z I0912 20:45:56.170924 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:56.176827652Z phc2sys[357163.612]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10095 delay 503 +2023-09-12T20:45:56.179028905Z dpll[1694551556]:[ts2phc.0.config] ens6f0 frequency_status 3 offset -3 phase_status 3 s2 +2023-09-12T20:45:56.239408431Z phc2sys[357163.674]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10099 delay 503 +2023-09-12T20:45:56.301998621Z phc2sys[357163.737]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10098 delay 502 +2023-09-12T20:45:56.364559300Z phc2sys[357163.799]: [ptp4l.0.config] CLOCK_REALTIME phc offset 4 s2 freq -10093 delay 504 +2023-09-12T20:45:56.427132773Z phc2sys[357163.862]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10091 delay 503 +2023-09-12T20:45:56.489749735Z phc2sys[357163.925]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10095 delay 503 +2023-09-12T20:45:56.552330289Z phc2sys[357163.987]: [ptp4l.0.config] CLOCK_REALTIME phc offset 6 s2 freq -10088 delay 502 +2023-09-12T20:45:56.614907166Z phc2sys[357164.050]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10095 delay 503 +2023-09-12T20:45:56.677494909Z phc2sys[357164.112]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10092 delay 502 +2023-09-12T20:45:56.740090387Z phc2sys[357164.175]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10093 delay 498 +2023-09-12T20:45:56.802660171Z phc2sys[357164.237]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10095 delay 505 +2023-09-12T20:45:56.865303595Z phc2sys[357164.300]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10095 delay 509 +2023-09-12T20:45:56.927828316Z phc2sys[357164.363]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10097 delay 504 +2023-09-12T20:45:56.990435640Z phc2sys[357164.425]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10092 delay 502 +2023-09-12T20:45:57.000091107Z ts2phc[357164.435]: [ts2phc.0.config] nmea delay: 114829942 ns +2023-09-12T20:45:57.000123383Z ts2phc[357164.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551594.000000000 corr 0 src 1694551594.885193460 diff 0 +2023-09-12T20:45:57.000123383Z ts2phc[357164.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:57.010321587Z I0912 20:45:57.010302 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:57.052995539Z phc2sys[357164.488]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10091 delay 503 +2023-09-12T20:45:57.109584161Z ts2phc[357164.544]: [ts2phc.0.config] nmea sentence: GNRMC,204557.00,A,4233.01586,N,07112.87878,W,0.015,,120923,,,A,V +2023-09-12T20:45:57.110097110Z ts2phc[357164.545]: [ts2phc.0.config] nmea sentence: GNGGA,204557.00,4233.01586,N,07112.87878,W,1,05,1.99,59.1,M,-33.0,M,, +2023-09-12T20:45:57.110148848Z ts2phc[357164.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.99,3.77,1 +2023-09-12T20:45:57.110148848Z ts2phc[357164.545]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.99,3.77,5 +2023-09-12T20:45:57.110205144Z ts2phc[357164.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,296,21,10,63,173,27,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:57.110238428Z ts2phc[357164.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,21,24,09,056,14,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:57.110264335Z ts2phc[357164.545]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,22,32,69,327,24,1 +2023-09-12T20:45:57.110298877Z ts2phc[357164.545]: [ts2phc.0.config] nmea sentence: GNGST,204557.00,40,14,11,122,4.8,5.5,11 +2023-09-12T20:45:57.110298877Z ts2phc[357164.545]: [ts2phc.0.config] nmea sentence: GNZDA,204557.00,12,09,2023,00,00 +2023-09-12T20:45:57.110298877Z ts2phc[357164.545]: [ts2phc.0.config] nmea sentence: GNGBS,204557.00,4.8,5.5,11.0,,,,,, +2023-09-12T20:45:57.112272875Z gnss[1694551557]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:57.115572988Z phc2sys[357164.550]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10090 delay 503 +2023-09-12T20:45:57.170963483Z I0912 20:45:57.170927 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:57.170963483Z I0912 20:45:57.170946 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:57.171042402Z I0912 20:45:57.171016 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:57.174195197Z dpll[1694551557]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 3 phase_status 3 s2 +2023-09-12T20:45:57.178188608Z phc2sys[357164.613]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10096 delay 503 +2023-09-12T20:45:57.240747204Z phc2sys[357164.676]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10099 delay 502 +2023-09-12T20:45:57.303328248Z phc2sys[357164.738]: [ptp4l.0.config] CLOCK_REALTIME phc offset 1 s2 freq -10094 delay 503 +2023-09-12T20:45:57.365916042Z phc2sys[357164.801]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10097 delay 503 +2023-09-12T20:45:57.428509066Z phc2sys[357164.863]: [ptp4l.0.config] CLOCK_REALTIME phc offset 11 s2 freq -10084 delay 483 +2023-09-12T20:45:57.491107890Z phc2sys[357164.926]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10098 delay 504 +2023-09-12T20:45:57.553677322Z phc2sys[357164.988]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10096 delay 502 +2023-09-12T20:45:57.616285105Z phc2sys[357165.051]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10096 delay 509 +2023-09-12T20:45:57.678890957Z phc2sys[357165.114]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10101 delay 504 +2023-09-12T20:45:57.741449984Z phc2sys[357165.176]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10100 delay 503 +2023-09-12T20:45:57.804036839Z phc2sys[357165.239]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10104 delay 503 +2023-09-12T20:45:57.866645168Z phc2sys[357165.301]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10105 delay 508 +2023-09-12T20:45:57.929235217Z phc2sys[357165.364]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10106 delay 503 +2023-09-12T20:45:57.991796006Z phc2sys[357165.427]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10106 delay 503 +2023-09-12T20:45:58.000073997Z ts2phc[357165.435]: [ts2phc.0.config] nmea delay: 109527177 ns +2023-09-12T20:45:58.000073997Z ts2phc[357165.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551595.000000000 corr 0 src 1694551595.890495868 diff 0 +2023-09-12T20:45:58.000104488Z ts2phc[357165.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:58.005271519Z I0912 20:45:58.005251 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:58.054503429Z phc2sys[357165.489]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10104 delay 507 +2023-09-12T20:45:58.109073510Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GNRMC,204558.00,A,4233.01584,N,07112.87876,W,0.015,,120923,,,A,V +2023-09-12T20:45:58.109686971Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GNGGA,204558.00,4233.01584,N,07112.87876,W,1,05,1.99,59.1,M,-33.0,M,, +2023-09-12T20:45:58.109776540Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.99,3.77,1 +2023-09-12T20:45:58.109776540Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.99,3.77,5 +2023-09-12T20:45:58.109776540Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,295,21,10,63,173,27,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:58.109776540Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,21,24,09,056,15,25,45,120,23,28,50,237,23,1 +2023-09-12T20:45:58.109776540Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GPGSV,3,3,10,31,20,232,21,32,69,327,25,1 +2023-09-12T20:45:58.109776540Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GNGST,204558.00,40,14,11,122,4.8,5.5,11 +2023-09-12T20:45:58.109776540Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GNZDA,204558.00,12,09,2023,00,00 +2023-09-12T20:45:58.109776540Z ts2phc[357165.544]: [ts2phc.0.config] nmea sentence: GNGBS,204558.00,4.8,5.5,11.0,,,,,, +2023-09-12T20:45:58.116961942Z phc2sys[357165.552]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10107 delay 503 +2023-09-12T20:45:58.118130666Z gnss[1694551558]:[ts2phc.0.config] ens6f0 gnss_status 3 offset 5 s2 +2023-09-12T20:45:58.171658325Z I0912 20:45:58.171632 161357 dpll.go:467] dpll decision: Status 3, Offset 0, In spec true, Source lost false, On holdover false +2023-09-12T20:45:58.171658325Z I0912 20:45:58.171647 161357 dpll.go:494] dpll is locked, source is not lost, offset is in range, state is DPLL_LOCKED_HO_ACQ or DPLL_HOLDOVER +2023-09-12T20:45:58.171658325Z I0912 20:45:58.171653 161357 dpll.go:540] dpll event sent +2023-09-12T20:45:58.179519445Z phc2sys[357165.614]: [ptp4l.0.config] CLOCK_REALTIME phc offset -5 s2 freq -10110 delay 504 +2023-09-12T20:45:58.179597537Z dpll[1694551558]:[ts2phc.0.config] ens6f0 frequency_status 3 offset 1 phase_status 3 s2 +2023-09-12T20:45:58.242089940Z phc2sys[357165.677]: [ptp4l.0.config] CLOCK_REALTIME phc offset -6 s2 freq -10112 delay 504 +2023-09-12T20:45:58.304678263Z phc2sys[357165.739]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10110 delay 503 +2023-09-12T20:45:58.367267911Z phc2sys[357165.802]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10109 delay 503 +2023-09-12T20:45:58.429891364Z phc2sys[357165.865]: [ptp4l.0.config] CLOCK_REALTIME phc offset -7 s2 freq -10116 delay 511 +2023-09-12T20:45:58.492423485Z phc2sys[357165.927]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10111 delay 502 +2023-09-12T20:45:58.555103303Z phc2sys[357165.990]: [ptp4l.0.config] CLOCK_REALTIME phc offset 2 s2 freq -10109 delay 499 +2023-09-12T20:45:58.617627746Z phc2sys[357166.052]: [ptp4l.0.config] CLOCK_REALTIME phc offset 3 s2 freq -10107 delay 503 +2023-09-12T20:45:58.680267543Z phc2sys[357166.115]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10110 delay 503 +2023-09-12T20:45:58.742808789Z phc2sys[357166.178]: [ptp4l.0.config] CLOCK_REALTIME phc offset -2 s2 freq -10111 delay 503 +2023-09-12T20:45:58.805369054Z phc2sys[357166.240]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10105 delay 503 +2023-09-12T20:45:58.867946867Z phc2sys[357166.303]: [ptp4l.0.config] CLOCK_REALTIME phc offset -1 s2 freq -10110 delay 503 +2023-09-12T20:45:58.930565573Z phc2sys[357166.365]: [ptp4l.0.config] CLOCK_REALTIME phc offset -3 s2 freq -10112 delay 506 +2023-09-12T20:45:58.993760978Z phc2sys[357166.428]: [ptp4l.0.config] CLOCK_REALTIME phc offset -4 s2 freq -10114 delay 512 +2023-09-12T20:45:59.000066163Z ts2phc[357166.435]: [ts2phc.0.config] nmea delay: 109019555 ns +2023-09-12T20:45:59.000066163Z ts2phc[357166.435]: [ts2phc.0.config] ens6f0 extts index 0 at 1694551596.000000000 corr 0 src 1694551596.891002258 diff 0 +2023-09-12T20:45:59.000066163Z ts2phc[357166.435]: [ts2phc.0.config] ens6f0 master offset 0 s2 freq +0 +2023-09-12T20:45:59.009317496Z I0912 20:45:59.009297 161357 event.go:362] dpll State s2, gnss State s2, ts2phc state s2, gm state s2, +2023-09-12T20:45:59.055744298Z phc2sys[357166.491]: [ptp4l.0.config] CLOCK_REALTIME phc offset 5 s2 freq -10106 delay 498 +2023-09-12T20:45:59.118307993Z phc2sys[357166.553]: [ptp4l.0.config] CLOCK_REALTIME phc offset 0 s2 freq -10109 delay 507 +2023-09-12T20:45:59.119575899Z ts2phc[357166.554]: [ts2phc.0.config] nmea sentence: GNRMC,204559.00,A,4233.01583,N,07112.87872,W,0.014,,120923,,,A,V +2023-09-12T20:45:59.120114023Z ts2phc[357166.555]: [ts2phc.0.config] nmea sentence: GNGGA,204559.00,4233.01583,N,07112.87872,W,1,05,1.99,59.1,M,-33.0,M,, +2023-09-12T20:45:59.120114023Z ts2phc[357166.555]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,10,12,23,28,32,,,,,,,,4.26,1.99,3.77,1 +2023-09-12T20:45:59.120114023Z ts2phc[357166.555]: [ts2phc.0.config] nmea sentence: GNGSA,A,3,,,,,,,,,,,,,4.26,1.99,3.77,5 +2023-09-12T20:45:59.120114023Z ts2phc[357166.555]: [ts2phc.0.config] nmea sentence: GPGSV,3,1,10,02,19,295,22,10,63,173,27,12,33,066,22,21,20,287,18,1 +2023-09-12T20:45:59.120114023Z ts2phc[357166.555]: [ts2phc.0.config] nmea sentence: GPGSV,3,2,10,23,25,153,20,24,09,056,15,25,45,120,23,28,50,237,23,1 diff --git a/pkg/runner/collector_selector.go b/pkg/runner/collector_selector.go index 36a90e01..4b2e6b60 100644 --- a/pkg/runner/collector_selector.go +++ b/pkg/runner/collector_selector.go @@ -51,8 +51,8 @@ func GetCollectorsToRun(selectedCollectors []string) []string { switch { case strings.EqualFold(name, "all"): collectorNames = append(collectorNames, OptionalCollectorNames...) - collectorNames = removeDuplicates(collectorNames) - return collectorNames + case strings.EqualFold(name, "defaults"): + collectorNames = append(collectorNames, OptionalCollectorNames...) case isIn(name, collectorNames): continue case isIn(name, OptionalCollectorNames): @@ -61,5 +61,6 @@ func GetCollectorsToRun(selectedCollectors []string) []string { log.Errorf("Unknown collector %s. Ignored", name) } } + collectorNames = removeDuplicates(collectorNames) return collectorNames } diff --git a/pkg/runner/runner.go b/pkg/runner/runner.go index d66aa06d..2b298897 100644 --- a/pkg/runner/runner.go +++ b/pkg/runner/runner.go @@ -60,13 +60,17 @@ func NewCollectorRunner(selectedCollectors []string) *CollectorRunner { // initialise will call theconstructor for each // value in collector name, it will panic if a collector name is not known. -func (runner *CollectorRunner) initialise( +func (runner *CollectorRunner) initialise( //nolint:funlen // allow a slightly long function callback callbacks.Callback, ptpInterface string, clientset *clients.Clientset, pollInterval int, requestedDuration time.Duration, devInfoAnnouceInterval int, + logsOutputFile string, + includeLogTimestamps bool, + tempDir string, + keepDebugFiles bool, ) { runner.pollInterval = pollInterval runner.endTime = time.Now().Add(requestedDuration) @@ -79,6 +83,10 @@ func (runner *CollectorRunner) initialise( PollInterval: pollInterval, DevInfoAnnouceInterval: devInfoAnnouceInterval, ErroredPolls: runner.erroredPolls, + LogsOutputFile: logsOutputFile, + IncludeLogTimestamps: includeLogTimestamps, + TempDir: tempDir, + KeepDebugFiles: keepDebugFiles, } registry := collectors.GetRegistry() @@ -151,6 +159,15 @@ func (runner *CollectorRunner) poller( runningPolls.Wait() return default: + log.Debug( + "Collector GoRoutine:", + collectorName, + lastPoll, pollInterval, + lastPoll.IsZero(), + time.Since(lastPoll), + time.Since(lastPoll) > pollInterval, + lastPoll.IsZero() || time.Since(lastPoll) > pollInterval, + ) if lastPoll.IsZero() || time.Since(lastPoll) > pollInterval { lastPoll = time.Now() log.Debugf("poll %s", collectorName) @@ -208,6 +225,10 @@ func (runner *CollectorRunner) Run( //nolint:funlen // allow a slightly long fun devInfoAnnouceInterval int, ptpInterface string, useAnalyserJSON bool, + logsOutputFile string, + includeLogTimestamps bool, + tempDir string, + keepDebugFiles bool, ) { clientset, err := clients.GetClientset(kubeConfig) utils.IfErrorExitOrPanic(err) @@ -219,7 +240,18 @@ func (runner *CollectorRunner) Run( //nolint:funlen // allow a slightly long fun callback, err := callbacks.SetupCallback(outputFile, outputFormat) utils.IfErrorExitOrPanic(err) - runner.initialise(callback, ptpInterface, clientset, pollInterval, requestedDuration, devInfoAnnouceInterval) + runner.initialise( + callback, + ptpInterface, + clientset, + pollInterval, + requestedDuration, + devInfoAnnouceInterval, + logsOutputFile, + includeLogTimestamps, + tempDir, + keepDebugFiles, + ) runner.start() // Use wg count to know if any collectors are running. diff --git a/pkg/utils/utils.go b/pkg/utils/utils.go index cf0bb742..761ce793 100644 --- a/pkg/utils/utils.go +++ b/pkg/utils/utils.go @@ -3,8 +3,12 @@ package utils import ( + "errors" "fmt" + "io/fs" "os" + "path/filepath" + "strings" "sync" "sync/atomic" "time" @@ -59,3 +63,19 @@ func ParseTimestamp(timestamp string) (time.Time, error) { } return Epoch.Add(duration).UTC(), nil } + +func RemoveTempFiles(dir string, filenames []string) { + dir = filepath.Clean(dir) + for _, fname := range filenames { + log.Info() + if !strings.HasPrefix(fname, dir) { + fname = filepath.Join(dir, fname) + } + err := os.Remove(fname) + if err != nil && errors.Is(err, fs.ErrNotExist) { + log.Errorf("Failed to remove temp file %s: %s", fname, err.Error()) + } + } + // os.Remove will not remove a director if has files so its safe to call on the Dir + os.Remove(dir) +}