From 4c6245a782d4a4ed213a6e591641ff810b14264d Mon Sep 17 00:00:00 2001 From: yzqzss Date: Mon, 21 Jul 2025 03:14:19 +0800 Subject: [PATCH 1/6] first Zeno E2E test! --- cmd/cmd.go | 10 +- e2e/e2e.go | 71 +++ e2e/log/log.go | 50 ++ e2e/log/log_test.go | 23 + e2e/log/testdata/zeno.log.data | 589 +++++++++++++++++++ e2e/log/util.go | 6 + e2e/test/cloudflare204/cloudflare204_test.go | 64 ++ e2e/test/cloudflare204/config.toml | 3 + go.mod | 2 + go.sum | 2 + internal/pkg/config/config.go | 4 +- internal/pkg/controler/signal.go | 1 - internal/pkg/log/config.go | 44 ++ internal/pkg/log/log.go | 4 + 14 files changed, 869 insertions(+), 4 deletions(-) create mode 100644 e2e/e2e.go create mode 100644 e2e/log/log.go create mode 100644 e2e/log/log_test.go create mode 100644 e2e/log/testdata/zeno.log.data create mode 100644 e2e/log/util.go create mode 100644 e2e/test/cloudflare204/cloudflare204_test.go create mode 100644 e2e/test/cloudflare204/config.toml diff --git a/cmd/cmd.go b/cmd/cmd.go index 0390fad7..f9e66855 100644 --- a/cmd/cmd.go +++ b/cmd/cmd.go @@ -36,12 +36,14 @@ Authors: } // Run the root command -func Run() error { +func Prepare() *cobra.Command { rootCmd.CompletionOptions.DisableDefaultCmd = true // Define flags and configuration settings rootCmd.PersistentFlags().String("log-level", "info", "stdout log level (debug, info, warn, error)") rootCmd.PersistentFlags().String("config-file", "", "config file (default is $HOME/zeno-config.yaml)") + rootCmd.PersistentFlags().String("log-socket", "", "socket log address (e.g. /tmp/zenolog.sock)") + rootCmd.PersistentFlags().String("log-socket-level", "info", "socket log level") rootCmd.PersistentFlags().Bool("no-stdout-log", false, "disable stdout logging.") rootCmd.PersistentFlags().Bool("no-stderr-log", false, "disable stderr logging.") rootCmd.PersistentFlags().Bool("no-color-logs", false, "switch the terminal (stdout and stderr) logging handler from [slogcolor] handler to the standard [slog] handler (help ensure compatibility with logging collectors)") @@ -53,5 +55,9 @@ func Run() error { getCmd := getCMDs() rootCmd.AddCommand(getCmd) - return rootCmd.Execute() + return rootCmd +} +func Run() error { + cmd := Prepare() + return cmd.Execute() } diff --git a/e2e/e2e.go b/e2e/e2e.go new file mode 100644 index 00000000..4137fe7c --- /dev/null +++ b/e2e/e2e.go @@ -0,0 +1,71 @@ +package e2e + +import ( + "context" + "fmt" + "io" + "net" + "sync" + "testing" + "time" + + "github.com/internetarchive/Zeno/cmd" + "github.com/internetarchive/Zeno/e2e/log" + "github.com/spf13/cobra" +) + +func CmdZenoGetURL(socketPath string, urls []string) *cobra.Command { + cmd := cmd.Prepare() + args := append([]string{"get", "url", "--config-file", "config.toml", "--log-socket-level", "debug", "--log-socket", socketPath}, urls...) + fmt.Println("Command arguments:", args) + cmd.SetArgs(args) + return cmd +} + +func lazyDial(socketPath string, timeout time.Duration) (net.Conn, error) { + ctx, cancel := context.WithTimeout(context.Background(), timeout) + defer cancel() + + var conn net.Conn + var err error + + for { + select { + case <-ctx.Done(): + return nil, fmt.Errorf("timeout while waiting for socket %s", socketPath) + default: + conn, err = net.Dial("unix", socketPath) + if err == nil { + return conn, nil + } + time.Sleep(100 * time.Millisecond) // Retry + } + } +} + +func ConnectSocketThenCopy(t *testing.T, wg *sync.WaitGroup, W *io.PipeWriter, socketPath string) { + defer wg.Done() + conn, err := lazyDial(socketPath, 5*time.Second) + if err != nil { + t.Errorf("failed to connect to log socket: %v", err) + } + defer conn.Close() + io.Copy(W, conn) + defer W.Close() +} + +func ExecuteCmdZenoGetURL(t *testing.T, wg *sync.WaitGroup, socketPath string, urls []string) { + defer wg.Done() + cmdErr := CmdZenoGetURL(socketPath, urls).Execute() + if cmdErr != nil { + t.Errorf("failed to start command: %v", cmdErr) + } +} + +func LogRecordProcessorWrapper(t *testing.T, R *io.PipeReader, rm log.RecordMatcher, wg *sync.WaitGroup) { + defer wg.Done() + err := log.LogRecordProcessor(R, rm.Match) + if err != nil { + t.Error("failed to listen to logs:", err) + } +} diff --git a/e2e/log/log.go b/e2e/log/log.go new file mode 100644 index 00000000..1655728b --- /dev/null +++ b/e2e/log/log.go @@ -0,0 +1,50 @@ +package log + +import ( + "fmt" + "io" + "testing" + + "github.com/go-logfmt/logfmt" +) + +type RecordMatcher interface { + Match(record map[string]string) + Assert(t *testing.T) +} + +func ParseLog(r io.Reader) chan map[string]string { + d := logfmt.NewDecoder(r) + out := make(chan map[string]string) + + go func() { + defer close(out) + for d.ScanRecord() { + record := make(map[string]string) + for d.ScanKeyval() { + if _, ok := record[string(d.Key())]; ok { + panic(fmt.Sprintf("duplicate key %s in record", d.Key())) + } + record[string(d.Key())] = string(d.Value()) + } + if !hasKey(record, "level") || !hasKey(record, "time") { + fmt.Printf("ignore record without level or time: %v\n", record) + continue + } + out <- record + } + if d.Err() != nil { + panic(d.Err()) + } + }() + return out +} + +func LogRecordProcessor(pipeR *io.PipeReader, matcher func(map[string]string)) error { + logCh := ParseLog(pipeR) + for record := range logCh { + matcher(record) + fmt.Printf("log record: %v\n", record) + } + return nil +} diff --git a/e2e/log/log_test.go b/e2e/log/log_test.go new file mode 100644 index 00000000..cca0fb09 --- /dev/null +++ b/e2e/log/log_test.go @@ -0,0 +1,23 @@ +package log + +import ( + "bytes" + _ "embed" + "testing" +) + +//go:embed testdata/zeno.log.data +var zenoLog []byte + +func TestParseLog(t *testing.T) { + logCh := ParseLog(bytes.NewReader(zenoLog)) + ok := false + for record := range logCh { + if record["msg"] == "done, logs are flushing and will be closed" { + ok = true + } + } + if !ok { + t.Error("expected log message not found") + } +} diff --git a/e2e/log/testdata/zeno.log.data b/e2e/log/testdata/zeno.log.data new file mode 100644 index 00000000..f9cb2813 --- /dev/null +++ b/e2e/log/testdata/zeno.log.data @@ -0,0 +1,589 @@ +time=2025-07-19T21:45:23.822+08:00 level=DEBUG msg=initialized component=reactor +time=2025-07-19T21:45:23.822+08:00 level=INFO msg=started component=reactor +time=2025-07-19T21:45:23.830+08:00 level=DEBUG msg=initialized component=preprocessor +time=2025-07-19T21:45:23.830+08:00 level=INFO msg=started component=preprocessor +time=2025-07-19T21:45:23.830+08:00 level=INFO msg="bucket manager started" component=archiver +time=2025-07-19T21:45:23.830+08:00 level=DEBUG msg=initialized component=archiver +time=2025-07-19T21:45:23.830+08:00 level=DEBUG msg="WARC writer started" component=archiver +time=2025-07-19T21:45:23.830+08:00 level=INFO msg=started component=archiver +time=2025-07-19T21:45:23.830+08:00 level=DEBUG msg=initialized component=postprocessor +time=2025-07-19T21:45:23.830+08:00 level=INFO msg=started component=postprocessor +time=2025-07-19T21:45:23.830+08:00 level=DEBUG msg="seenchecker set" component=preprocessor +time=2025-07-19T21:45:23.830+08:00 level=INFO msg="starting source" component=controler.StartPipeline source="Local Queue" +time=2025-07-19T21:45:24.573+08:00 level=INFO msg=started component=lq +time=2025-07-19T21:45:24.573+08:00 level=DEBUG msg=initialized component=finisher +time=2025-07-19T21:45:24.573+08:00 level=INFO msg=started component=finisher +time=2025-07-19T21:45:24.573+08:00 level=DEBUG msg="received item" component=reactor item=b30f2 +time=2025-07-19T21:45:24.573+08:00 level=DEBUG msg="received seed" component=preprocessor.worker worker_id=2 seed=b30f2 +time=2025-07-19T21:45:24.574+08:00 level=DEBUG msg="received seed" component=archiver.worker worker_id=2 seed=b30f2 depth=0 hops=0 +time=2025-07-19T21:45:24.574+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=2 seed_id=b30f2 item_id=b30f2 depth=0 hops=0 elapsed=2.432µs +time=2025-07-19T21:45:24.574+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:24.825+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:25.074+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=2 url=https://blog.save-web.org/blog/2025/05/18/archive-if-summer-is-calling-us/ seed_id=b30f2 item_id=b30f2 depth=0 hops=0 status=200 +time=2025-07-19T21:45:25.074+08:00 level=DEBUG msg="received seed" component=postprocessor.worker worker_id=3 seed=b30f2 +time=2025-07-19T21:45:25.074+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=b30f2 +time=2025-07-19T21:45:25.074+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=b30f2 +time=2025-07-19T21:45:25.075+08:00 level=DEBUG msg="unable to extract URLs from JSON in script tag" component=postprocessor.extractor.HTMLAssets error="invalid character '\\\\' looking for beginning of value" url=https://blog.save-web.org/blog/2025/05/18/archive-if-summer-is-calling-us/ item=b30f2 +time=2025-07-19T21:45:25.075+08:00 level=DEBUG msg="unable to extract URLs from JSON in script tag" component=postprocessor.extractor.HTMLAssets error="invalid character 'w' looking for beginning of value" url=https://blog.save-web.org/blog/2025/05/18/archive-if-summer-is-calling-us/ item=b30f2 +time=2025-07-19T21:45:25.076+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:25.078+08:00 level=DEBUG msg="removing asset that is a duplicate of the item URL" component=postprocessor.ExtractAssets item=b30f2 asset=https://blog.save-web.org/blog/2025/05/18/archive-if-summer-is-calling-us/ +time=2025-07-19T21:45:25.078+08:00 level=DEBUG msg="removing asset that is a duplicate of the item URL" component=postprocessor.ExtractAssets item=b30f2 asset=https://blog.save-web.org/blog/2025/05/18/archive-if-summer-is-calling-us/ +time=2025-07-19T21:45:25.078+08:00 level=DEBUG msg="removing asset that is a duplicate of the item URL" component=postprocessor.ExtractAssets item=b30f2 asset=https://blog.save-web.org/blog/2025/05/18/archive-if-summer-is-calling-us/ +time=2025-07-19T21:45:25.078+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=b30f2 count=32 +time=2025-07-19T21:45:25.078+08:00 level=DEBUG msg="received seed" component=finisher.worker worker_id=2 seed=b30f2 +time=2025-07-19T21:45:25.078+08:00 level=DEBUG msg="seed has fresh children" component=finisher.worker worker_id=2 seed=b30f2 +time=2025-07-19T21:45:25.078+08:00 level=DEBUG msg="received seed" component=preprocessor.worker worker_id=0 seed=b30f2 +time=2025-07-19T21:45:25.079+08:00 level=DEBUG msg="removing child with empty path" component=preprocessor.preprocess worker_id=0 item_id=ebe64 url=https://stats.wp.com/ +time=2025-07-19T21:45:25.079+08:00 level=DEBUG msg="removing child with empty path" component=preprocessor.preprocess worker_id=0 item_id=3be83 url=https://fonts.googleapis.com/ +time=2025-07-19T21:45:25.079+08:00 level=DEBUG msg="removing child with empty path" component=preprocessor.preprocess worker_id=0 item_id=4945c url="https://blog.save-web.org/?p=482" +time=2025-07-19T21:45:25.079+08:00 level=DEBUG msg="received seed" component=archiver.worker worker_id=0 seed=b30f2 depth=0 hops=0 +time=2025-07-19T21:45:25.079+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=ed202 depth=1 hops=0 elapsed=2.516µs +time=2025-07-19T21:45:25.079+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=e295c depth=1 hops=0 elapsed=2.017µs +time=2025-07-19T21:45:25.079+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=c6fc0 depth=1 hops=0 elapsed=3.633µs +time=2025-07-19T21:45:25.079+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=c9517 depth=1 hops=0 elapsed=2.597µs +time=2025-07-19T21:45:25.327+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:25.457+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://secure.gravatar.com/avatar/82fb1836567b7ebb1587337701c38b34c9b0ba0b860d0750f682ce665930df42?d=retro&r=g&s=48" seed_id=b30f2 item_id=c9517 depth=1 hops=0 status=200 +time=2025-07-19T21:45:25.457+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=de436 depth=1 hops=0 elapsed=1.215µs +time=2025-07-19T21:45:25.459+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://secure.gravatar.com/avatar/82fb1836567b7ebb1587337701c38b34c9b0ba0b860d0750f682ce665930df42?s=96&d=retro&r=g" seed_id=b30f2 item_id=c6fc0 depth=1 hops=0 status=200 +time=2025-07-19T21:45:25.459+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=106a1 depth=1 hops=0 elapsed=3.876µs +time=2025-07-19T21:45:25.552+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-content/plugins/jetpack/_inc/build/related-posts/related-posts.min.js?ver=20240116" seed_id=b30f2 item_id=e295c depth=1 hops=0 status=200 +time=2025-07-19T21:45:25.552+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=d46a2 depth=1 hops=0 elapsed=2.57µs +time=2025-07-19T21:45:25.578+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:25.830+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:26.045+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-includes/js/comment-reply.min.js?ver=6.8.2" seed_id=b30f2 item_id=d46a2 depth=1 hops=0 status=200 +time=2025-07-19T21:45:26.045+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=a97b4 depth=1 hops=0 elapsed=5.918µs +time=2025-07-19T21:45:26.068+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-includes/js/jquery/jquery-migrate.min.js?ver=3.4.1" seed_id=b30f2 item_id=de436 depth=1 hops=0 status=200 +time=2025-07-19T21:45:26.068+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=f4b98 depth=1 hops=0 elapsed=2.452µs +time=2025-07-19T21:45:26.081+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:26.301+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url=https://stats.wp.com/e-202529.js seed_id=b30f2 item_id=a97b4 depth=1 hops=0 status=200 +time=2025-07-19T21:45:26.301+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=e79e0 depth=1 hops=0 elapsed=1.138µs +time=2025-07-19T21:45:26.332+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:26.520+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-content/themes/period/js/build/production.min.js?ver=6.8.2" seed_id=b30f2 item_id=106a1 depth=1 hops=0 status=200 +time=2025-07-19T21:45:26.520+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=b63aa depth=1 hops=0 elapsed=3.938µs +time=2025-07-19T21:45:26.582+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:26.692+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-content/plugins/akismet/_inc/akismet-frontend.js?ver=1749649724" seed_id=b30f2 item_id=f4b98 depth=1 hops=0 status=200 +time=2025-07-19T21:45:26.692+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=31945 depth=1 hops=0 elapsed=2.947µs +time=2025-07-19T21:45:26.814+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-content/plugins/jetpack/modules/related-posts/related-posts.css?ver=20240116" seed_id=b30f2 item_id=e79e0 depth=1 hops=0 status=200 +time=2025-07-19T21:45:26.814+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=698d9 depth=1 hops=0 elapsed=5.414µs +time=2025-07-19T21:45:26.834+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:27.085+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-includes/css/dist/block-library/style.min.css?ver=6.8.2" seed_id=b30f2 item_id=b63aa depth=1 hops=0 status=200 +time=2025-07-19T21:45:27.085+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=ee9f0 depth=1 hops=0 elapsed=3.939µs +time=2025-07-19T21:45:27.085+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:27.197+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-includes/js/mediaelement/mediaelementplayer-legacy.min.css?ver=4.2.17" seed_id=b30f2 item_id=31945 depth=1 hops=0 status=200 +time=2025-07-19T21:45:27.197+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=7c7fd depth=1 hops=0 elapsed=1.907µs +time=2025-07-19T21:45:27.304+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-includes/js/mediaelement/wp-mediaelement.min.css?ver=6.8.2" seed_id=b30f2 item_id=698d9 depth=1 hops=0 status=200 +time=2025-07-19T21:45:27.304+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=51574 depth=1 hops=0 elapsed=965ns +time=2025-07-19T21:45:27.336+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:27.337+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://fonts.googleapis.com/css?display=swap&ver=6.8.2&family=Roboto%3A300%2C300italic%2C400%2C700&subset=latin%2Clatin-ext" seed_id=b30f2 item_id=ee9f0 depth=1 hops=0 status=200 +time=2025-07-19T21:45:27.337+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=65df5 depth=1 hops=0 elapsed=976ns +time=2025-07-19T21:45:27.410+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-includes/js/jquery/jquery.min.js?ver=3.7.1" seed_id=b30f2 item_id=ed202 depth=1 hops=0 status=200 +time=2025-07-19T21:45:27.410+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=2695b depth=1 hops=0 elapsed=1.301µs +time=2025-07-19T21:45:27.588+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:27.796+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-content/themes/period/assets/font-awesome/css/all.min.css?ver=6.8.2" seed_id=b30f2 item_id=7c7fd depth=1 hops=0 status=200 +time=2025-07-19T21:45:27.796+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=87103 depth=1 hops=0 elapsed=2.517µs +time=2025-07-19T21:45:27.839+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:28.008+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/xmlrpc.php?rsd=" seed_id=b30f2 item_id=2695b depth=1 hops=0 status=200 +time=2025-07-19T21:45:28.008+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=54d9e depth=1 hops=0 elapsed=3.095µs +time=2025-07-19T21:45:28.025+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url="https://blog.save-web.org/wp-content/themes/period/style.css?ver=6.8.2" seed_id=b30f2 item_id=51574 depth=1 hops=0 status=200 +time=2025-07-19T21:45:28.025+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=69dc4 depth=1 hops=0 elapsed=1.949µs +time=2025-07-19T21:45:28.090+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:28.097+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url=https://blog.save-web.org/wp-json/ seed_id=b30f2 item_id=65df5 depth=1 hops=0 status=200 +time=2025-07-19T21:45:28.097+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=0 seed_id=b30f2 item_id=d2dc8 depth=1 hops=0 elapsed=2.661µs +time=2025-07-19T21:45:28.286+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url=https://blog.save-web.org/wp-content/uploads/2021/07/cropped-save-the-web_nice-32x32.png seed_id=b30f2 item_id=87103 depth=1 hops=0 status=200 +time=2025-07-19T21:45:28.341+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:28.528+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url=https://blog.save-web.org/wp-content/uploads/2021/07/cropped-save-the-web_nice-180x180.png seed_id=b30f2 item_id=69dc4 depth=1 hops=0 status=200 +time=2025-07-19T21:45:28.583+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url=https://blog.save-web.org/wp-content/uploads/2021/07/cropped-save-the-web_nice-270x270.png seed_id=b30f2 item_id=d2dc8 depth=1 hops=0 status=200 +time=2025-07-19T21:45:28.584+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=0 url=https://blog.save-web.org/wp-content/uploads/2021/07/cropped-save-the-web_nice-192x192.png seed_id=b30f2 item_id=54d9e depth=1 hops=0 status=200 +time=2025-07-19T21:45:28.584+08:00 level=DEBUG msg="received seed" component=postprocessor.worker worker_id=5 seed=b30f2 +time=2025-07-19T21:45:28.584+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=c9517 +time=2025-07-19T21:45:28.584+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=c9517 +time=2025-07-19T21:45:28.584+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=c9517 +time=2025-07-19T21:45:28.584+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=c6fc0 +time=2025-07-19T21:45:28.584+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=c6fc0 +time=2025-07-19T21:45:28.584+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=c6fc0 +time=2025-07-19T21:45:28.584+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=e295c +time=2025-07-19T21:45:28.584+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=e295c +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="no extractor used for page" component=postprocessor.ExtractAssets content-type=text/javascript mime=text/javascript item=e295c +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=e295c count=0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=e295c +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=ed202 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=ed202 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="no extractor used for page" component=postprocessor.ExtractAssets content-type=text/javascript mime=text/javascript item=ed202 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=ed202 count=0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=ed202 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=de436 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=de436 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="no extractor used for page" component=postprocessor.ExtractAssets content-type=text/javascript mime=text/javascript item=de436 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=de436 count=0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=de436 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=106a1 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=106a1 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="no extractor used for page" component=postprocessor.ExtractAssets content-type=text/javascript mime=text/javascript item=106a1 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=106a1 count=0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=106a1 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=d46a2 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=d46a2 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="no extractor used for page" component=postprocessor.ExtractAssets content-type=text/javascript mime=text/javascript item=d46a2 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=d46a2 count=0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=d46a2 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=a97b4 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=a97b4 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="no extractor used for page" component=postprocessor.ExtractAssets content-type=application/javascript mime=text/javascript item=a97b4 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=a97b4 count=0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=a97b4 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=f4b98 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=f4b98 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="no extractor used for page" component=postprocessor.ExtractAssets content-type=text/javascript mime=text/javascript item=f4b98 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=f4b98 count=0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=f4b98 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=e79e0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=e79e0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=e79e0 links=0 at_import_links=0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=e79e0 count=0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=e79e0 +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=b63aa +time=2025-07-19T21:45:28.585+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=b63aa +time=2025-07-19T21:45:28.587+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=b63aa links=2 at_import_links=0 +time=2025-07-19T21:45:28.587+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=b63aa count=0 +time=2025-07-19T21:45:28.587+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=b63aa +time=2025-07-19T21:45:28.587+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=31945 +time=2025-07-19T21:45:28.587+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=31945 +time=2025-07-19T21:45:28.587+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=31945 links=3 at_import_links=0 +time=2025-07-19T21:45:28.587+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=31945 count=3 +time=2025-07-19T21:45:28.587+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=698d9 +time=2025-07-19T21:45:28.587+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=698d9 +time=2025-07-19T21:45:28.588+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=698d9 links=0 at_import_links=0 +time=2025-07-19T21:45:28.588+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=698d9 count=0 +time=2025-07-19T21:45:28.588+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=698d9 +time=2025-07-19T21:45:28.588+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=ee9f0 +time=2025-07-19T21:45:28.588+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=ee9f0 +time=2025-07-19T21:45:28.588+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=ee9f0 links=4 at_import_links=0 +time=2025-07-19T21:45:28.588+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=ee9f0 count=4 +time=2025-07-19T21:45:28.588+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=7c7fd +time=2025-07-19T21:45:28.588+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=7c7fd +time=2025-07-19T21:45:28.589+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=7c7fd links=20 at_import_links=0 +time=2025-07-19T21:45:28.589+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=7c7fd count=20 +time=2025-07-19T21:45:28.589+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=51574 +time=2025-07-19T21:45:28.589+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=51574 +time=2025-07-19T21:45:28.590+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=51574 links=0 at_import_links=0 +time=2025-07-19T21:45:28.590+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=51574 count=0 +time=2025-07-19T21:45:28.590+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=51574 +time=2025-07-19T21:45:28.590+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=65df5 +time=2025-07-19T21:45:28.590+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=65df5 +time=2025-07-19T21:45:28.592+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=65df5 count=10 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=2695b +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=2695b +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=2695b count=4 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=87103 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=87103 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=87103 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=54d9e +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=54d9e +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=54d9e +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=69dc4 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=69dc4 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=69dc4 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=d2dc8 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=d2dc8 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=d2dc8 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="received seed" component=finisher.worker worker_id=5 seed=b30f2 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="seed has fresh children" component=finisher.worker worker_id=5 seed=b30f2 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="received seed" component=preprocessor.worker worker_id=1 seed=b30f2 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="received seed" component=archiver.worker worker_id=1 seed=b30f2 depth=0 hops=0 +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=08cf8 depth=2 hops=0 elapsed=2.16µs +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=d1901 depth=2 hops=0 elapsed=1.43µs +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=ebeca depth=2 hops=0 elapsed=517ns +time=2025-07-19T21:45:28.603+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=21767 depth=2 hops=0 elapsed=835ns +time=2025-07-19T21:45:28.843+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:28.932+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://fonts.gstatic.com/s/roboto/v48/KFOMCnqEu92Fr1ME7kSn66aGLdTylUAMQXC89YmC2DPNWuaabVmaiA8.ttf seed_id=b30f2 item_id=21767 depth=2 hops=0 status=200 +time=2025-07-19T21:45:28.932+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=4a4cb depth=2 hops=0 elapsed=3.49µs +time=2025-07-19T21:45:28.999+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://fonts.gstatic.com/s/roboto/v48/KFOKCnqEu92Fr1Mu53ZEC9_Vu3r1gIhOszmOClHrs6ljXfMMLt_QuAb-lg.ttf seed_id=b30f2 item_id=d1901 depth=2 hops=0 status=200 +time=2025-07-19T21:45:28.999+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=c8295 depth=2 hops=0 elapsed=2.548µs +time=2025-07-19T21:45:29.023+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://fonts.gstatic.com/s/roboto/v48/KFOMCnqEu92Fr1ME7kSn66aGLdTylUAMQXC89YmC2DPNWubEbVmaiA8.ttf seed_id=b30f2 item_id=08cf8 depth=2 hops=0 status=200 +time=2025-07-19T21:45:29.023+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=a51ff depth=2 hops=0 elapsed=3.355µs +time=2025-07-19T21:45:29.089+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-includes/js/mediaelement/mejs-controls.svg seed_id=b30f2 item_id=ebeca depth=2 hops=0 status=200 +time=2025-07-19T21:45:29.090+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=f819b depth=2 hops=0 elapsed=4.057µs +time=2025-07-19T21:45:29.094+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:29.345+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:29.597+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:29.641+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://fonts.gstatic.com/s/roboto/v48/KFOMCnqEu92Fr1ME7kSn66aGLdTylUAMQXC89YmC2DPNWuYjalmaiA8.ttf seed_id=b30f2 item_id=4a4cb depth=2 hops=0 status=200 +time=2025-07-19T21:45:29.642+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=4a0b6 depth=2 hops=0 elapsed=3.373µs +time=2025-07-19T21:45:29.842+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-content/themes/period/assets/font-awesome/webfonts/fa-brands-400.woff2 seed_id=b30f2 item_id=c8295 depth=2 hops=0 status=200 +time=2025-07-19T21:45:29.842+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=4758a depth=2 hops=0 elapsed=4.061µs +time=2025-07-19T21:45:29.848+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:30.013+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-content/themes/period/assets/font-awesome/webfonts/fa-regular-400.woff2 seed_id=b30f2 item_id=f819b depth=2 hops=0 status=200 +time=2025-07-19T21:45:30.013+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=73c0b depth=2 hops=0 elapsed=3.09µs +time=2025-07-19T21:45:30.098+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:30.244+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-content/themes/period/assets/font-awesome/webfonts/fa-regular-400.ttf seed_id=b30f2 item_id=4a0b6 depth=2 hops=0 status=200 +time=2025-07-19T21:45:30.244+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=eda83 depth=2 hops=0 elapsed=4.805µs +time=2025-07-19T21:45:30.349+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:30.411+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-content/themes/period/assets/font-awesome/webfonts/fa-brands-400.ttf seed_id=b30f2 item_id=a51ff depth=2 hops=0 status=200 +time=2025-07-19T21:45:30.411+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=483b9 depth=2 hops=0 elapsed=1.704µs +time=2025-07-19T21:45:30.600+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:30.689+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-content/themes/period/assets/font-awesome/webfonts/fa-solid-900.woff2 seed_id=b30f2 item_id=4758a depth=2 hops=0 status=200 +time=2025-07-19T21:45:30.690+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=d426c depth=2 hops=0 elapsed=1.941µs +time=2025-07-19T21:45:30.752+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-content/themes/period/assets/font-awesome/webfonts/fa-v4compatibility.woff2 seed_id=b30f2 item_id=eda83 depth=2 hops=0 status=200 +time=2025-07-19T21:45:30.752+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=65ab5 depth=2 hops=0 elapsed=1.206µs +time=2025-07-19T21:45:30.851+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:31.015+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-content/themes/period/assets/font-awesome/webfonts/fa-solid-900.ttf seed_id=b30f2 item_id=73c0b depth=2 hops=0 status=200 +time=2025-07-19T21:45:31.015+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=f24ef depth=2 hops=0 elapsed=2.867µs +time=2025-07-19T21:45:31.103+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:31.245+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-json/oembed/1.0 seed_id=b30f2 item_id=d426c depth=2 hops=0 status=200 +time=2025-07-19T21:45:31.245+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=a0db7 depth=2 hops=0 elapsed=5.462µs +time=2025-07-19T21:45:31.341+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-json/.*/S.* seed_id=b30f2 item_id=65ab5 depth=2 hops=0 status=404 +time=2025-07-19T21:45:31.341+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=1 seed_id=b30f2 item_id=ac157 depth=2 hops=0 elapsed=4.154µs +time=2025-07-19T21:45:31.353+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:31.605+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:31.634+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-content/uploads/2021/07/cropped-save-the-web_nice.png seed_id=b30f2 item_id=f24ef depth=2 hops=0 status=200 +time=2025-07-19T21:45:31.856+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:31.966+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/xmlrpc.php seed_id=b30f2 item_id=ac157 depth=2 hops=0 status=405 +time=2025-07-19T21:45:31.983+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-content/themes/period/assets/font-awesome/webfonts/fa-v4compatibility.ttf seed_id=b30f2 item_id=483b9 depth=2 hops=0 status=200 +time=2025-07-19T21:45:32.107+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:32.358+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:32.609+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:32.860+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:32.976+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=1 url=https://blog.save-web.org/wp-admin/authorize-application.php seed_id=b30f2 item_id=a0db7 depth=2 hops=0 status=302 +time=2025-07-19T21:45:32.976+08:00 level=DEBUG msg="received seed" component=postprocessor.worker worker_id=0 seed=b30f2 +time=2025-07-19T21:45:32.976+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=ebeca +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=ebeca +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="no extractor used for page" component=postprocessor.ExtractAssets content-type=image/svg+xml mime=image/svg+xml item=ebeca +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=ebeca count=0 +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=ebeca +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=d1901 +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=d1901 +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=d1901 +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=21767 +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=21767 +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=21767 +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=08cf8 +time=2025-07-19T21:45:32.977+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=08cf8 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=08cf8 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=4a4cb +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=4a4cb +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=4a4cb +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=c8295 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=c8295 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=c8295 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=a51ff +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=a51ff +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=a51ff +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=f819b +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=f819b +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=f819b +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=4a0b6 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=4a0b6 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=4a0b6 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=4758a +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=4758a +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=4758a +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=73c0b +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=73c0b +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=73c0b +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=eda83 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=eda83 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=eda83 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=483b9 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=483b9 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=483b9 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=d426c +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=d426c +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="removing asset that is a duplicate of the item URL" component=postprocessor.ExtractAssets item=d426c asset=https://blog.save-web.org/wp-json/oembed/1.0 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=d426c count=5 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=65ab5 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=65ab5 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=f24ef +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=f24ef +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=f24ef +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=a0db7 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item is a redirection" component=postprocessor.postprocess.postprocessItem item_id=a0db7 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=ac157 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=ac157 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="received seed" component=finisher.worker worker_id=4 seed=b30f2 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="seed has fresh children" component=finisher.worker worker_id=4 seed=b30f2 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="received seed" component=preprocessor.worker worker_id=6 seed=b30f2 +time=2025-07-19T21:45:32.978+08:00 level=DEBUG msg="received seed" component=archiver.worker worker_id=4 seed=b30f2 depth=0 hops=0 +time=2025-07-19T21:45:32.979+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=4 seed_id=b30f2 item_id=2313e depth=3 hops=0 elapsed=3.146µs +time=2025-07-19T21:45:32.979+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=4 seed_id=b30f2 item_id=58d5a depth=3 hops=0 elapsed=4.321µs +time=2025-07-19T21:45:33.111+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:33.362+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:33.614+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:33.747+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=4 url=https://blog.save-web.org/wp-json/oembed/oembed/1.0 seed_id=b30f2 item_id=58d5a depth=3 hops=0 status=404 +time=2025-07-19T21:45:33.865+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:34.116+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:34.367+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:34.619+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:34.871+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:35.122+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:35.373+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:35.444+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=4 url="https://blog.save-web.org/wp-login.php?redirect_to=https%3A%2F%2Fblog.save-web.org%2Fwp-admin%2Fauthorize-application.php&reauth=1" seed_id=b30f2 item_id=2313e depth=3 hops=0 status=200 +time=2025-07-19T21:45:35.444+08:00 level=DEBUG msg="received seed" component=postprocessor.worker worker_id=4 seed=b30f2 +time=2025-07-19T21:45:35.444+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=58d5a +time=2025-07-19T21:45:35.444+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=58d5a +time=2025-07-19T21:45:35.444+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=2313e +time=2025-07-19T21:45:35.444+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=2313e +time=2025-07-19T21:45:35.444+08:00 level=DEBUG msg="unable to extract URLs from JSON in script tag" component=postprocessor.extractor.HTMLAssets error=EOF url="https://blog.save-web.org/wp-login.php?redirect_to=https%3A%2F%2Fblog.save-web.org%2Fwp-admin%2Fauthorize-application.php&reauth=1" item=2313e +time=2025-07-19T21:45:35.445+08:00 level=DEBUG msg="unable to extract URLs from JSON in script tag" component=postprocessor.extractor.HTMLAssets error="invalid character 'd' looking for beginning of value" url="https://blog.save-web.org/wp-login.php?redirect_to=https%3A%2F%2Fblog.save-web.org%2Fwp-admin%2Fauthorize-application.php&reauth=1" item=2313e +time=2025-07-19T21:45:35.445+08:00 level=DEBUG msg="unable to extract URLs from JSON in script tag" component=postprocessor.extractor.HTMLAssets error="invalid character 'a' in literal true (expecting 'u')" url="https://blog.save-web.org/wp-login.php?redirect_to=https%3A%2F%2Fblog.save-web.org%2Fwp-admin%2Fauthorize-application.php&reauth=1" item=2313e +time=2025-07-19T21:45:35.445+08:00 level=DEBUG msg="unable to extract URLs from JSON in script tag" component=postprocessor.extractor.HTMLAssets error="invalid character 'a' in literal true (expecting 'u')" url="https://blog.save-web.org/wp-login.php?redirect_to=https%3A%2F%2Fblog.save-web.org%2Fwp-admin%2Fauthorize-application.php&reauth=1" item=2313e +time=2025-07-19T21:45:35.445+08:00 level=DEBUG msg="unable to extract URLs from JSON in script tag" component=postprocessor.extractor.HTMLAssets error="invalid character 'a' in literal true (expecting 'u')" url="https://blog.save-web.org/wp-login.php?redirect_to=https%3A%2F%2Fblog.save-web.org%2Fwp-admin%2Fauthorize-application.php&reauth=1" item=2313e +time=2025-07-19T21:45:35.445+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=2313e count=37 +time=2025-07-19T21:45:35.445+08:00 level=DEBUG msg="received seed" component=finisher.worker worker_id=7 seed=b30f2 +time=2025-07-19T21:45:35.445+08:00 level=DEBUG msg="seed has fresh children" component=finisher.worker worker_id=7 seed=b30f2 +time=2025-07-19T21:45:35.445+08:00 level=DEBUG msg="received seed" component=preprocessor.worker worker_id=4 seed=b30f2 +time=2025-07-19T21:45:35.446+08:00 level=DEBUG msg="received seed" component=archiver.worker worker_id=3 seed=b30f2 depth=0 hops=0 +time=2025-07-19T21:45:35.446+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=01783 depth=4 hops=0 elapsed=3.766µs +time=2025-07-19T21:45:35.446+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=f0d31 depth=4 hops=0 elapsed=3.75µs +time=2025-07-19T21:45:35.446+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=7292d depth=4 hops=0 elapsed=2.834µs +time=2025-07-19T21:45:35.446+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=9a456 depth=4 hops=0 elapsed=3.583µs +time=2025-07-19T21:45:35.624+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:35.876+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:35.922+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/js/clipboard.min.js?ver=2.0.11" seed_id=b30f2 item_id=7292d depth=4 hops=0 status=200 +time=2025-07-19T21:45:35.922+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=75b31 depth=4 hops=0 elapsed=3.56µs +time=2025-07-19T21:45:35.930+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-content/plugins/jetpack/jetpack_vendor/automattic/jetpack-connection/dist/jetpack-sso-login.js?minify=false" seed_id=b30f2 item_id=f0d31 depth=4 hops=0 status=200 +time=2025-07-19T21:45:35.930+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=cabae depth=4 hops=0 elapsed=3.88µs +time=2025-07-19T21:45:35.931+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-content/plugins/jetpack/jetpack_vendor/automattic/jetpack-connection/dist/jetpack-sso-login.js?minify=false&ver=6.11.8" seed_id=b30f2 item_id=9a456 depth=4 hops=0 status=200 +time=2025-07-19T21:45:35.931+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=415bf depth=4 hops=0 elapsed=2.043µs +time=2025-07-19T21:45:36.127+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:36.378+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:36.410+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/js/zxcvbn-async.min.js?ver=1.0" seed_id=b30f2 item_id=75b31 depth=4 hops=0 status=200 +time=2025-07-19T21:45:36.410+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=0c96b depth=4 hops=0 elapsed=3.17µs +time=2025-07-19T21:45:36.421+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/js/dist/hooks.min.js?ver=4d63a3d491d11ffd8ac6" seed_id=b30f2 item_id=cabae depth=4 hops=0 status=200 +time=2025-07-19T21:45:36.422+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=ded86 depth=4 hops=0 elapsed=2.473µs +time=2025-07-19T21:45:36.630+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:36.795+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/js/dist/i18n.min.js?ver=5e580eb46a90c2b997e6" seed_id=b30f2 item_id=415bf depth=4 hops=0 status=200 +time=2025-07-19T21:45:36.795+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=6f5a5 depth=4 hops=0 elapsed=1.913µs +time=2025-07-19T21:45:36.881+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:36.901+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-admin/js/password-strength-meter.min.js?ver=6.8.2" seed_id=b30f2 item_id=0c96b depth=4 hops=0 status=200 +time=2025-07-19T21:45:36.902+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=a2ce4 depth=4 hops=0 elapsed=1.871µs +time=2025-07-19T21:45:37.132+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:37.292+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/js/underscore.min.js?ver=1.13.7" seed_id=b30f2 item_id=ded86 depth=4 hops=0 status=200 +time=2025-07-19T21:45:37.292+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=6b6fb depth=4 hops=0 elapsed=3.298µs +time=2025-07-19T21:45:37.384+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:37.393+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/js/dist/dom-ready.min.js?ver=f77871ff7694fffea381" seed_id=b30f2 item_id=a2ce4 depth=4 hops=0 status=200 +time=2025-07-19T21:45:37.394+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=bf092 depth=4 hops=0 elapsed=7.233µs +time=2025-07-19T21:45:37.635+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:37.659+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/js/wp-util.min.js?ver=6.8.2" seed_id=b30f2 item_id=6f5a5 depth=4 hops=0 status=200 +time=2025-07-19T21:45:37.659+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=1f682 depth=4 hops=0 elapsed=3.372µs +time=2025-07-19T21:45:37.789+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/js/dist/a11y.min.js?ver=3156534cc54473497e14" seed_id=b30f2 item_id=6b6fb depth=4 hops=0 status=200 +time=2025-07-19T21:45:37.789+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=4b756 depth=4 hops=0 elapsed=2.595µs +time=2025-07-19T21:45:37.887+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:37.994+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-admin/js/user-profile.min.js?ver=6.8.2" seed_id=b30f2 item_id=bf092 depth=4 hops=0 status=200 +time=2025-07-19T21:45:37.994+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=243a7 depth=4 hops=0 elapsed=3.299µs +time=2025-07-19T21:45:38.138+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:38.330+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/css/dashicons.min.css?ver=6.8.2" seed_id=b30f2 item_id=1f682 depth=4 hops=0 status=200 +time=2025-07-19T21:45:38.330+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=e5a7a depth=4 hops=0 elapsed=2.535µs +time=2025-07-19T21:45:38.389+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:38.393+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-includes/css/buttons.min.css?ver=6.8.2" seed_id=b30f2 item_id=4b756 depth=4 hops=0 status=200 +time=2025-07-19T21:45:38.393+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=3451f depth=4 hops=0 elapsed=6.587µs +time=2025-07-19T21:45:38.641+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:38.871+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-admin/css/login.min.css?ver=6.8.2" seed_id=b30f2 item_id=3451f depth=4 hops=0 status=200 +time=2025-07-19T21:45:38.871+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=3 seed_id=b30f2 item_id=cc556 depth=4 hops=0 elapsed=2.854µs +time=2025-07-19T21:45:38.893+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:38.927+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-admin/css/forms.min.css?ver=6.8.2" seed_id=b30f2 item_id=243a7 depth=4 hops=0 status=200 +time=2025-07-19T21:45:39.144+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:39.221+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-admin/css/l10n.min.css?ver=6.8.2" seed_id=b30f2 item_id=e5a7a depth=4 hops=0 status=200 +time=2025-07-19T21:45:39.394+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:39.438+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url="https://blog.save-web.org/wp-content/plugins/jetpack/jetpack_vendor/automattic/jetpack-connection/dist/jetpack-sso-login.css?minify=false&ver=6.11.8" seed_id=b30f2 item_id=cc556 depth=4 hops=0 status=200 +time=2025-07-19T21:45:39.646+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:39.678+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=3 url=https://blog.save-web.org/wp-includes/js/zxcvbn.min.js seed_id=b30f2 item_id=01783 depth=4 hops=0 status=200 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="received seed" component=postprocessor.worker worker_id=1 seed=b30f2 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=9a456 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=9a456 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=f0d31 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=f0d31 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=7292d +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=7292d +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=01783 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=01783 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=75b31 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=75b31 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=cabae +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=cabae +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=415bf +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=415bf +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=0c96b +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=0c96b +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=ded86 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=ded86 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=6f5a5 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=6f5a5 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=a2ce4 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=a2ce4 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=6b6fb +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=6b6fb +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=bf092 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=bf092 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=1f682 +time=2025-07-19T21:45:39.678+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=1f682 +time=2025-07-19T21:45:39.679+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=1f682 links=4 at_import_links=0 +time=2025-07-19T21:45:39.679+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=1f682 count=3 +time=2025-07-19T21:45:39.679+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=4b756 +time=2025-07-19T21:45:39.679+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=4b756 +time=2025-07-19T21:45:39.680+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=4b756 links=0 at_import_links=0 +time=2025-07-19T21:45:39.680+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=4b756 count=0 +time=2025-07-19T21:45:39.680+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=4b756 +time=2025-07-19T21:45:39.680+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=243a7 +time=2025-07-19T21:45:39.680+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=243a7 +time=2025-07-19T21:45:39.680+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=243a7 links=4 at_import_links=0 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=243a7 count=1 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=e5a7a +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=e5a7a +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=e5a7a links=0 at_import_links=0 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=e5a7a count=0 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=e5a7a +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=3451f +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=3451f +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=3451f links=2 at_import_links=0 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=3451f count=2 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=cc556 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="item is a success" component=postprocessor.postprocess.postprocessItem item_id=cc556 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="extracted assets from CSS" component=postprocessor.ExtractAssets item=cc556 links=0 at_import_links=0 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="extracted assets" component=postprocessor.postprocess.postprocessItem item_id=cc556 count=0 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="item has no children, setting as completed" component=postprocessor.postprocess.postprocessItem item_id=cc556 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="received seed" component=finisher.worker worker_id=6 seed=b30f2 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="seed has fresh children" component=finisher.worker worker_id=6 seed=b30f2 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="received seed" component=preprocessor.worker worker_id=3 seed=b30f2 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="received seed" component=archiver.worker worker_id=6 seed=b30f2 depth=0 hops=0 +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=6 seed_id=b30f2 item_id=9340e depth=5 hops=0 elapsed=2.106µs +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=6 seed_id=b30f2 item_id=35c59 depth=5 hops=0 elapsed=2.318µs +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=6 seed_id=b30f2 item_id=cccf5 depth=5 hops=0 elapsed=1.602µs +time=2025-07-19T21:45:39.681+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=6 seed_id=b30f2 item_id=32534 depth=5 hops=0 elapsed=2.54µs +time=2025-07-19T21:45:39.897+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:40.148+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:40.152+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=6 url=https://blog.save-web.org/wp-admin/images/loading.gif seed_id=b30f2 item_id=32534 depth=5 hops=0 status=200 +time=2025-07-19T21:45:40.152+08:00 level=DEBUG msg="got token from bucket" component=archiver.archive worker_id=6 seed_id=b30f2 item_id=48c24 depth=5 hops=0 elapsed=2.024µs +time=2025-07-19T21:45:40.161+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=6 url="https://blog.save-web.org/wp-admin/images/w-logo-blue.png?ver=20131202" seed_id=b30f2 item_id=9340e depth=5 hops=0 status=200 +time=2025-07-19T21:45:40.374+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=6 url="https://blog.save-web.org/wp-includes/fonts/dashicons.ttf?99ac726223c749443b642ce33df8b800=" seed_id=b30f2 item_id=35c59 depth=5 hops=0 status=200 +time=2025-07-19T21:45:40.384+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=6 url="https://blog.save-web.org/wp-includes/fonts/dashicons.eot?99ac726223c749443b642ce33df8b800=" seed_id=b30f2 item_id=cccf5 depth=5 hops=0 status=200 +time=2025-07-19T21:45:40.399+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:40.630+08:00 level=INFO msg="url archived" component=archiver.archive worker_id=6 url="https://blog.save-web.org/wp-admin/images/wordpress-logo.svg?ver=20131107" seed_id=b30f2 item_id=48c24 depth=5 hops=0 status=200 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="received seed" component=postprocessor.worker worker_id=6 seed=b30f2 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=cccf5 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=cccf5 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=35c59 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=35c59 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=32534 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=32534 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=9340e +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=9340e +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="postprocessing item" component=postprocessor.postprocess.postprocessItem item_id=48c24 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="item is a child and it's depth (without redirections) is more than 2" component=postprocessor.postprocess.postprocessItem item_id=48c24 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="received seed" component=finisher.worker worker_id=0 seed=b30f2 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="seed has no fresh redirection or children" component=finisher.worker worker_id=0 seed=b30f2 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="seed finished" component=finisher.worker worker_id=0 seed=b30f2 +time=2025-07-19T21:45:40.631+08:00 level=DEBUG msg="received item" component=lq.finisherReceiver item=b30f2 +time=2025-07-19T21:45:40.651+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:40.902+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:41.153+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:41.404+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:41.575+08:00 level=DEBUG msg="sending non-full batch to dispatcher" component=lq.finisherReceiver size=1 +time=2025-07-19T21:45:41.575+08:00 level=DEBUG msg="dispatching batch to sender" component=lq.finisherDispatcher size=1 +time=2025-07-19T21:45:41.575+08:00 level=DEBUG msg="sending batch to LQ" component=lq.finisherSender.969af8 size=1 +time=2025-07-19T21:45:41.575+08:00 level=DEBUG msg=done component=lq.finisherSender.969af8 +time=2025-07-19T21:45:41.655+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:41.906+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:42.157+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:42.408+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:42.660+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:42.911+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:43.163+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:43.414+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:43.665+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:43.916+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:44.167+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:44.418+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:44.670+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:44.920+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:45.171+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:45.421+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:45.673+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:45.924+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:46.174+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:46.426+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:46.503+08:00 level=INFO msg="received shutdown signal, stopping services..." component=controler.signalWatcher +time=2025-07-19T21:45:46.503+08:00 level=DEBUG msg=closed component=controler.diskWatcher +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg=closed component=controler.warcWritingQueueWatcher.stats +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="received freeze signal" component=reactor +time=2025-07-19T21:45:46.504+08:00 level=INFO msg=frozen component=reactor +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=preprocessor.worker worker_id=7 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=preprocessor.worker worker_id=7 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=preprocessor.worker worker_id=3 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=preprocessor.worker worker_id=3 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=preprocessor.worker worker_id=4 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=preprocessor.worker worker_id=4 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=preprocessor.worker worker_id=2 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=preprocessor.worker worker_id=2 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=preprocessor.worker worker_id=0 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=preprocessor.worker worker_id=0 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=preprocessor.worker worker_id=6 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=preprocessor.worker worker_id=6 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=preprocessor.worker worker_id=5 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=preprocessor.worker worker_id=5 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=preprocessor.worker worker_id=1 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=preprocessor.worker worker_id=1 +time=2025-07-19T21:45:46.504+08:00 level=INFO msg=stopped component=preprocessor +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=archiver.worker worker_id=6 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=archiver.worker worker_id=0 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=archiver.worker worker_id=5 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=archiver.worker worker_id=5 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=archiver.worker worker_id=0 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=archiver.worker worker_id=7 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=archiver.worker worker_id=1 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=archiver.worker worker_id=4 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=archiver.worker worker_id=4 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=archiver.worker worker_id=6 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=archiver.worker worker_id=1 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=archiver.worker worker_id=7 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=archiver.worker worker_id=2 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=archiver.worker worker_id=2 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="shutting down" component=archiver.worker worker_id=3 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="worker stopped" component=archiver.worker worker_id=3 +time=2025-07-19T21:45:46.504+08:00 level=DEBUG msg="WARC writing finished" component=archiver +time=2025-07-19T21:45:46.677+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:46.929+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:47.180+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:47.431+08:00 level=DEBUG msg="feed is empty, waiting for new URLs" component=lq.consumerFetcher +time=2025-07-19T21:45:47.504+08:00 level=INFO msg=stopped component=archiver +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="closing bucket manager" component=archiver +time=2025-07-19T21:45:47.505+08:00 level=INFO msg="closed bucket manager" component=archiver +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=postprocessor.worker worker_id=2 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=postprocessor.worker worker_id=6 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=postprocessor.worker worker_id=1 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=postprocessor.worker worker_id=4 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=postprocessor.worker worker_id=3 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=postprocessor.worker worker_id=7 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=postprocessor.worker worker_id=5 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=postprocessor.worker worker_id=0 +time=2025-07-19T21:45:47.505+08:00 level=INFO msg=stopped component=postprocessor +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="received stop signal" component=finisher +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=finisher.worker worker_id=3 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=finisher.worker worker_id=4 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=finisher.worker worker_id=7 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=finisher.worker worker_id=2 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=finisher.worker worker_id=1 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=finisher.worker worker_id=6 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=finisher.worker worker_id=0 +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="shutting down" component=finisher.worker worker_id=5 +time=2025-07-19T21:45:47.505+08:00 level=INFO msg=stopped component=finisher +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="waiting for sender routines to finish" component=lq.finisherDispatcher +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="received done signal" component=lq.consumer +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg=closed component=lq.consumerSender +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg=closed component=lq.finisherReceiver +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg=closing component=lq.producerReceiver +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg=closed component=lq.finisherDispatcher +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="received done signal" component=lq.producer +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="waiting for goroutines to finish" component=lq.producer +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg=closed component=lq.producer +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="received done signal" component=.q.finisher +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="waiting for goroutines to finish" component=.q.finisher +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg=closed component=.q.finisher +time=2025-07-19T21:45:47.505+08:00 level=DEBUG msg="waiting for goroutines to finish" component=lq.consumer +time=2025-07-19T21:45:47.681+08:00 level=DEBUG msg=closed component=lq.consumerFetcher +time=2025-07-19T21:45:47.681+08:00 level=DEBUG msg=closed component=lq.consumer +time=2025-07-19T21:45:47.681+08:00 level=INFO msg=stopped component=lq +time=2025-07-19T21:45:47.682+08:00 level=DEBUG msg="received stop signal" component=reactor +time=2025-07-19T21:45:47.682+08:00 level=DEBUG msg="shutting down" component=reactor +time=2025-07-19T21:45:47.682+08:00 level=INFO msg=stopped component=reactor +time=2025-07-19T21:45:47.682+08:00 level=INFO msg="done, logs are flushing and will be closed" component=controler.stopPipeline +Log file closed diff --git a/e2e/log/util.go b/e2e/log/util.go new file mode 100644 index 00000000..04a5bd80 --- /dev/null +++ b/e2e/log/util.go @@ -0,0 +1,6 @@ +package log + +func hasKey(record map[string]string, key string) bool { + _, ok := record[key] + return ok +} diff --git a/e2e/test/cloudflare204/cloudflare204_test.go b/e2e/test/cloudflare204/cloudflare204_test.go new file mode 100644 index 00000000..21b25428 --- /dev/null +++ b/e2e/test/cloudflare204/cloudflare204_test.go @@ -0,0 +1,64 @@ +package boot + +import ( + _ "embed" + "fmt" + "io" + "os" + "path" + "sync" + "syscall" + "testing" + "time" + + "github.com/internetarchive/Zeno/e2e" +) + +type recordMatcher struct { + stoppedOK bool + urlArchived bool +} + +func (rm *recordMatcher) Match(record map[string]string) { + if record["msg"] == "done, logs are flushing and will be closed" { + rm.stoppedOK = true + } + if record["msg"] == "url archived" && record["url"] == "http://cp.cloudflare.com/" && record["status"] == "204" { + rm.urlArchived = true + } +} + +func (rm *recordMatcher) Assert(t *testing.T) { + if !rm.stoppedOK { + t.Error("Zeno did not stop gracefully") + } + if !rm.urlArchived { + t.Error("URL was not archived") + } +} + +func TestCloudFlare204(t *testing.T) { + os.RemoveAll("jobs") + + tmpDir := os.TempDir() + tempSocketPath := path.Join(tmpDir, fmt.Sprintf("zeno-%d.sock", os.Getpid())) + defer os.Remove(tempSocketPath) + + R, W := io.Pipe() + + rm := &recordMatcher{} + wg := &sync.WaitGroup{} + wg.Add(3) + + go e2e.LogRecordProcessorWrapper(t, R, rm, wg) + go e2e.ExecuteCmdZenoGetURL(t, wg, tempSocketPath, []string{"http://cp.cloudflare.com/"}) + go e2e.ConnectSocketThenCopy(t, wg, W, tempSocketPath) + + time.Sleep(5 * time.Second) + + // send self a termination signal to stop + syscall.Kill(os.Getpid(), syscall.SIGTERM) + + wg.Wait() + rm.Assert(t) +} diff --git a/e2e/test/cloudflare204/config.toml b/e2e/test/cloudflare204/config.toml new file mode 100644 index 00000000..c9be368e --- /dev/null +++ b/e2e/test/cloudflare204/config.toml @@ -0,0 +1,3 @@ +# custom configuration for Zeno e2e tests +no-stderr-log = true +no-stdout-log = true \ No newline at end of file diff --git a/go.mod b/go.mod index 2c6ea762..73a430a7 100644 --- a/go.mod +++ b/go.mod @@ -12,6 +12,7 @@ require ( github.com/fatih/color v1.18.0 github.com/gabriel-vasile/mimetype v1.4.9 github.com/gdamore/tcell/v2 v2.8.1 + github.com/go-logfmt/logfmt v0.4.0 github.com/google/uuid v1.6.0 github.com/grafana/pyroscope-go v1.2.4 github.com/grafov/m3u8 v0.12.1 @@ -64,6 +65,7 @@ require ( github.com/hhrutter/tiff v1.0.2 // indirect github.com/inconshreveable/mousetrap v1.1.0 // indirect github.com/klauspost/compress v1.18.0 // indirect + github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515 // indirect github.com/lucasb-eyer/go-colorful v1.2.0 // indirect github.com/mattn/go-colorable v0.1.13 // indirect github.com/mattn/go-isatty v0.0.20 // indirect diff --git a/go.sum b/go.sum index db19e2b1..30326311 100644 --- a/go.sum +++ b/go.sum @@ -64,6 +64,7 @@ github.com/gdamore/tcell/v2 v2.8.1/go.mod h1:bj8ori1BG3OYMjmb3IklZVWfZUJ1UBQt9JX github.com/go-kit/kit v0.8.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as= github.com/go-kit/kit v0.9.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as= github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9GBnD5lWE= +github.com/go-logfmt/logfmt v0.4.0 h1:MP4Eh7ZCb31lleYCFuwm0oe4/YGak+5l1vA2NOE80nA= github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk= github.com/go-stack/stack v1.8.0/go.mod h1:v0f6uXyyMGvRgIKkXu+yp6POWl0qKG85gN/melR3HDY= github.com/go-test/deep v1.1.0 h1:WOcxcdHcvdgThNXjw0t76K42FXTU7HpNQWHpA2HHNlg= @@ -164,6 +165,7 @@ github.com/julienschmidt/httprouter v1.2.0/go.mod h1:SYymIcj16QtmaHHD7aYtjjsJG7V github.com/klauspost/compress v1.18.0 h1:c/Cqfb0r+Yi+JtIEq73FWXVkRonBlf0CRNYc8Zttxdo= github.com/klauspost/compress v1.18.0/go.mod h1:2Pp+KzxcywXVXMr50+X0Q/Lsb43OQHYWRCY2AiWywWQ= github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ= +github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515 h1:T+h1c/A9Gawja4Y9mFVWj2vyii2bbUNDw3kt9VxK2EY= github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515/go.mod h1:+0opPa2QZZtGFBFZlji/RkVcI2GknAs/DXo4wKdlNEc= github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo= github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE= diff --git a/internal/pkg/config/config.go b/internal/pkg/config/config.go index 41261f39..87928570 100644 --- a/internal/pkg/config/config.go +++ b/internal/pkg/config/config.go @@ -98,6 +98,8 @@ type Config struct { NoStderrLogging bool `mapstructure:"no-stderr-log"` NoColorLogging bool `mapstructure:"no-color-logs"` NoFileLogging bool `mapstructure:"no-log-file"` + SocketLogging string `mapstructure:"log-socket"` + SocketLevel string `mapstructure:"log-socket-level"` StdoutLogLevel string `mapstructure:"log-level"` TUI bool `mapstructure:"tui"` TUILogLevel string `mapstructure:"tui-log-level"` @@ -210,7 +212,7 @@ func Get() *Config { // Useful for testing func Set(cfg *Config) { - config = cfg + config = cfg } func GenerateCrawlConfig() error { diff --git a/internal/pkg/controler/signal.go b/internal/pkg/controler/signal.go index ee59feb3..15830664 100644 --- a/internal/pkg/controler/signal.go +++ b/internal/pkg/controler/signal.go @@ -33,6 +33,5 @@ func WatchSignals() { }() Stop() - os.Exit(0) } } diff --git a/internal/pkg/log/config.go b/internal/pkg/log/config.go index 3188755d..7c187030 100644 --- a/internal/pkg/log/config.go +++ b/internal/pkg/log/config.go @@ -5,7 +5,9 @@ import ( "context" "fmt" "io" + stdliblog "log" "log/slog" + "net" "os" "strings" "time" @@ -19,6 +21,7 @@ import ( var ( rotatedLogFile *rotatedFile + socketCfg *socketConfig ) type logConfig struct { @@ -27,6 +30,8 @@ type logConfig struct { StdoutLevel slog.Level StderrEnabled bool StderrLevel slog.Level + SocketEnabled bool + SocketConfig *socketConfig NoColor bool LogTUI bool TUILogLevel slog.Level @@ -40,6 +45,13 @@ type logfileConfig struct { RotatePeriod time.Duration } +type socketConfig struct { + SocketPath string + Level slog.Level + NetListener net.Listener + Conn net.Conn +} + // makeConfig returns the default configuration func makeConfig() *logConfig { if config.Get() == nil { @@ -76,12 +88,36 @@ func makeConfig() *logConfig { logFileConfig = nil } + if config.Get().SocketLogging != "" { + socketPath := config.Get().SocketLogging + os.Remove(socketPath) // Clean up any old socket + listener, err := net.Listen("unix", socketPath) + if err != nil { + stdliblog.Fatalf("Error listening: %v", err) + } + stdliblog.Printf("Listening on Unix socket: %s", socketPath) + + conn, err := listener.Accept() + if err != nil { + stdliblog.Fatalf("Error accepting connection: %v", err) + } + stdliblog.Println("Client connected!") + socketCfg = &socketConfig{ + Level: parseLevel(config.Get().SocketLevel), + SocketPath: socketPath, + NetListener: listener, + Conn: conn, + } + } + return &logConfig{ FileConfig: logFileConfig, StdoutEnabled: !config.Get().NoStdoutLogging, StdoutLevel: parseLevel(config.Get().StdoutLogLevel), StderrEnabled: !config.Get().NoStderrLogging, StderrLevel: slog.LevelError, + SocketEnabled: config.Get().SocketLogging != "", + SocketConfig: socketCfg, NoColor: config.Get().NoColorLogging, LogTUI: config.Get().TUI, TUILogLevel: parseLevel(config.Get().TUILogLevel), @@ -155,6 +191,14 @@ func (c *logConfig) makeMultiLogger() *slog.Logger { }) } + // Handle socket logging configuration + if c.SocketEnabled && c.SocketConfig != nil { + socketHandler := slog.NewTextHandler(c.SocketConfig.Conn, &slog.HandlerOptions{Level: c.SocketConfig.Level}) // TODO: socket level + baseRouter = baseRouter.Add(socketHandler, func(_ context.Context, r slog.Record) bool { + return r.Level >= c.SocketConfig.Level + }) + } + // Handle TUI logging configuration if c.LogTUI { TUIRingBuffer = ringbuffer.NewMP1COverwritingRingBuffer[string](16384) diff --git a/internal/pkg/log/log.go b/internal/pkg/log/log.go index bcb2f8f1..693b0d8f 100644 --- a/internal/pkg/log/log.go +++ b/internal/pkg/log/log.go @@ -37,6 +37,10 @@ func Stop() { if rotatedLogFile != nil { rotatedLogFile.Close() } + if socketCfg != nil { + socketCfg.NetListener.Close() + socketCfg.Conn.Close() + } wg.Wait() multiLogger = nil once = sync.Once{} From 5ae475146bcb39f0c3637357d6618acb0e275a91 Mon Sep 17 00:00:00 2001 From: yzqzss Date: Mon, 21 Jul 2025 03:43:19 +0800 Subject: [PATCH 2/6] increace wait time for race test --- e2e/test/cloudflare204/cloudflare204_test.go | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/e2e/test/cloudflare204/cloudflare204_test.go b/e2e/test/cloudflare204/cloudflare204_test.go index 21b25428..f8ff4f50 100644 --- a/e2e/test/cloudflare204/cloudflare204_test.go +++ b/e2e/test/cloudflare204/cloudflare204_test.go @@ -17,6 +17,7 @@ import ( type recordMatcher struct { stoppedOK bool urlArchived bool + errored bool } func (rm *recordMatcher) Match(record map[string]string) { @@ -26,6 +27,9 @@ func (rm *recordMatcher) Match(record map[string]string) { if record["msg"] == "url archived" && record["url"] == "http://cp.cloudflare.com/" && record["status"] == "204" { rm.urlArchived = true } + if record["level"] == "ERROR" { + rm.errored = true + } } func (rm *recordMatcher) Assert(t *testing.T) { @@ -35,6 +39,9 @@ func (rm *recordMatcher) Assert(t *testing.T) { if !rm.urlArchived { t.Error("URL was not archived") } + if rm.errored { + t.Error("An error was logged during the test") + } } func TestCloudFlare204(t *testing.T) { @@ -54,7 +61,7 @@ func TestCloudFlare204(t *testing.T) { go e2e.ExecuteCmdZenoGetURL(t, wg, tempSocketPath, []string{"http://cp.cloudflare.com/"}) go e2e.ConnectSocketThenCopy(t, wg, W, tempSocketPath) - time.Sleep(5 * time.Second) + time.Sleep(10 * time.Second) // send self a termination signal to stop syscall.Kill(os.Getpid(), syscall.SIGTERM) From 3201a176e1b64ea4046554071f9437c0289ec2c7 Mon Sep 17 00:00:00 2001 From: yzqzss Date: Mon, 21 Jul 2025 03:58:40 +0800 Subject: [PATCH 3/6] CI: disable -race test for e2e --- .github/workflows/go.yml | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index 29793198..7938aa4d 100644 --- a/.github/workflows/go.yml +++ b/.github/workflows/go.yml @@ -25,7 +25,10 @@ jobs: run: go build -v ./... - name: Test - run: go test -race -v ./... + run: go test -race -v $(go list ./... | grep -v /e2e/test/) + + - name: E2E Test + run: go test -v $(go list ./e2e/test/...) - name: Goroutine leak detector run: go test -c -o tests && for test in $(go test -list . | grep -E "^(Test|Example)"); do ./tests -test.run "^$test\$" &>/dev/null && echo -e "$test passed\n" || echo -e "$test failed\n"; done From d253cbf1ce127ea8e1bc3a5de8343759fc013a13 Mon Sep 17 00:00:00 2001 From: yzqzss Date: Tue, 22 Jul 2025 04:35:19 +0800 Subject: [PATCH 4/6] CI: generate coverage report --- .github/workflows/go.yml | 16 ++++++++++++++-- e2e/test/cloudflare204/config.toml | 2 +- 2 files changed, 15 insertions(+), 3 deletions(-) diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index 7938aa4d..6b8c8e7c 100644 --- a/.github/workflows/go.yml +++ b/.github/workflows/go.yml @@ -24,11 +24,23 @@ jobs: - name: Build run: go build -v ./... + - name: Make Coverage Dirs + run: mkdir -p /tmp/unit_coverage /tmp/e2e_coverage + - name: Test - run: go test -race -v $(go list ./... | grep -v /e2e/test/) + run: go test -v -race -cover -coverpkg=./... $(go list ./... | grep -v /e2e/test/) -args -test.gocoverdir=/tmp/unit_coverage - name: E2E Test - run: go test -v $(go list ./e2e/test/...) + run: go test -v -cover -covermode=atomic -coverpkg=./... $(go list ./e2e/test/...) -args -test.gocoverdir=/tmp/e2e_coverage + + - name: Merge Coverage + run: go tool covdata textfmt -i /tmp/unit_coverage/,/tmp/e2e_coverage/ -o coverage.txt + + - name: Upload coverage reports to Codecov + uses: codecov/codecov-action@v5 + continue-on-error: true + with: + token: ${{ secrets.CODECOV_TOKEN }} - name: Goroutine leak detector run: go test -c -o tests && for test in $(go test -list . | grep -E "^(Test|Example)"); do ./tests -test.run "^$test\$" &>/dev/null && echo -e "$test passed\n" || echo -e "$test failed\n"; done diff --git a/e2e/test/cloudflare204/config.toml b/e2e/test/cloudflare204/config.toml index c9be368e..369c7af8 100644 --- a/e2e/test/cloudflare204/config.toml +++ b/e2e/test/cloudflare204/config.toml @@ -1,3 +1,3 @@ # custom configuration for Zeno e2e tests no-stderr-log = true -no-stdout-log = true \ No newline at end of file +no-stdout-log = true From 7b94c820d5962dd4d453472ad3b67a2af7ae87fd Mon Sep 17 00:00:00 2001 From: yzqzss Date: Tue, 22 Jul 2025 04:53:21 +0800 Subject: [PATCH 5/6] flag the coverage reports --- .github/workflows/go.yml | 21 +++++++++++++++++---- 1 file changed, 17 insertions(+), 4 deletions(-) diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index 6b8c8e7c..5123fb1c 100644 --- a/.github/workflows/go.yml +++ b/.github/workflows/go.yml @@ -24,7 +24,7 @@ jobs: - name: Build run: go build -v ./... - - name: Make Coverage Dirs + - name: Make coverage dirs run: mkdir -p /tmp/unit_coverage /tmp/e2e_coverage - name: Test @@ -33,13 +33,26 @@ jobs: - name: E2E Test run: go test -v -cover -covermode=atomic -coverpkg=./... $(go list ./e2e/test/...) -args -test.gocoverdir=/tmp/e2e_coverage - - name: Merge Coverage - run: go tool covdata textfmt -i /tmp/unit_coverage/,/tmp/e2e_coverage/ -o coverage.txt + - name: Convert coverage reports + run: | + go tool covdata textfmt -i /tmp/unit_coverage/ -o unit_coverage.txt + go tool covdata textfmt -i /tmp/e2e_coverage/ -o e2e_coverage.txt - - name: Upload coverage reports to Codecov + + - name: Upload coverage reports to Codecov (unittests) + uses: codecov/codecov-action@v5 + continue-on-error: true + with: + flags: unittests + files: unit_coverage.txt + token: ${{ secrets.CODECOV_TOKEN }} + + - name: Upload coverage reports to Codecov (e2e tests) uses: codecov/codecov-action@v5 continue-on-error: true with: + flags: e2etests + files: e2e_coverage.txt token: ${{ secrets.CODECOV_TOKEN }} - name: Goroutine leak detector From b55584cecbde2bedbc9301a425d8e5ea7113d7ed Mon Sep 17 00:00:00 2001 From: yzqzss Date: Tue, 22 Jul 2025 05:03:34 +0800 Subject: [PATCH 6/6] CI: codecov: disable_search --- .github/workflows/go.yml | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index 5123fb1c..db67b691 100644 --- a/.github/workflows/go.yml +++ b/.github/workflows/go.yml @@ -44,7 +44,8 @@ jobs: continue-on-error: true with: flags: unittests - files: unit_coverage.txt + files: ./unit_coverage.txt + disable_search: true token: ${{ secrets.CODECOV_TOKEN }} - name: Upload coverage reports to Codecov (e2e tests) @@ -52,7 +53,8 @@ jobs: continue-on-error: true with: flags: e2etests - files: e2e_coverage.txt + files: ./e2e_coverage.txt + disable_search: true token: ${{ secrets.CODECOV_TOKEN }} - name: Goroutine leak detector