niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #314
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenScriptFails97=== CONT TestScriptTokenEmptyCommand98--- PASS: TestScriptTokenEmptyCommand (0.00s)99=== CONT TestEncodeNixBase32WithRealHash100--- PASS: TestEncodeNixBase32WithRealHash (0.00s)101=== CONT TestFilterOversizedClosures102=== CONT TestPartSizeForNAR103=== RUN TestPartSizeForNAR/zero_stays_at_minimum104=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess105=== CONT TestRateLimiterFeedback106=== RUN TestRateLimiterFeedback/429_enables_limiter107=== CONT TestDoWithRetry_BodyReplayedViaGetBody108=== PAUSE TestRateLimiterFeedback/429_enables_limiter109=== RUN TestRateLimiterFeedback/503_enables_limiter110=== CONT TestPathInfoCACompatibility111=== RUN TestPathInfoCACompatibility/null_ca_field112=== PAUSE TestPathInfoCACompatibility/null_ca_field113=== RUN TestPathInfoCACompatibility/old_string_format_-_text114=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text115=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive116=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive117=== RUN TestPathInfoCACompatibility/new_structured_format_-_text118=== CONT TestScriptTokenBadJSON119=== CONT TestParsePathInfoJSONMultiplePaths120=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths121=== CONT TestScriptTokenEmptyToken122--- PASS: TestScriptTokenScriptFails (0.00s)123=== CONT TestStaticToken124=== CONT TestScriptTokenCachesUntilRefresh1252026/10/01 09:42:24 WARN Rate limiter enabled after throttle name=server-test rate=5126--- PASS: TestStaticToken (0.00s)127=== CONT TestUploadMultipart_PartsInParallel128=== CONT TestScriptTokenNoExpiryRerunsEveryCall129=== CONT TestPathInfoHashCompatibility130=== CONT TestFileTokenEmpty131=== CONT TestUploadMultipart_SupersededByPeer132=== RUN TestUploadMultipart_SupersededByPeer/exists133=== CONT TestGetStorePathHash134=== CONT TestFileTokenMissing135=== CONT TestConvertHashToNix32136=== CONT TestDumpPathSingleFile137=== CONT TestFileTokenReadsAndCaches138=== CONT TestDumpPathMatchesNix139=== CONT TestResolveStorePath140=== RUN TestFilterOversizedClosures/no_limit_keeps_everything141=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum142=== PAUSE TestRateLimiterFeedback/503_enables_limiter143=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text144=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths145=== CONT TestParsePathInfoJSON146=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)147--- PASS: TestFileTokenEmpty (0.00s)148=== CONT TestCaseHackSuffix149--- PASS: TestScriptTokenBadJSON (0.01s)150=== CONT TestSetClientTLSErrors151--- PASS: TestScriptTokenEmptyToken (0.01s)152=== CONT TestEncodeNixBase32153=== PAUSE TestUploadMultipart_SupersededByPeer/exists154=== RUN TestPartSizeForNAR/small_stays_at_minimum155=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter156=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter157=== RUN TestGetStorePathHash/valid_store_path158=== PAUSE TestGetStorePathHash/valid_store_path159=== RUN TestGetStorePathHash/basename_without_hyphen_should_error160=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error161=== RUN TestConvertHashToNix32/SRI_format_to_Nix32162=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32163=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method164=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method165=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error166=== RUN TestEncodeNixBase32/test_string_hash167=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter168=== RUN TestParsePathInfoJSON/Nix_format169=== PAUSE TestParsePathInfoJSON/Nix_format170=== PAUSE TestPartSizeForNAR/small_stays_at_minimum171=== PAUSE TestEncodeNixBase32/test_string_hash172=== RUN TestEncodeNixBase32/empty_input173=== PAUSE TestEncodeNixBase32/empty_input174=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything175=== CONT TestRegisterUploadedObjectReusesConnections176=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped177=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped1782026/10/01 09:42:24 WARN Rate limiter enabled after throttle name=server-test rate=5179=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1802026/10/01 09:42:24 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34393181--- PASS: TestDoServerRequestAttachesToken (0.03s)182=== CONT TestSetClientTLS1832026/10/01 09:42:24 WARN Rate limiter backed off name=server-test rate=51842026/10/01 09:42:24 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34393185--- PASS: TestFileTokenMissing (0.00s)186=== CONT TestStreamPushIsolatesFailures187--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)188=== CONT TestStreamPushBatchesUnderLoad189--- PASS: TestFileTokenReadsAndCaches (0.00s)190=== CONT TestShellSplitErrors191--- PASS: TestShellSplitErrors (0.00s)192=== CONT TestShellSplit1932026/10/01 09:42:24 ERROR Upload failed error="bad path" count=3194--- PASS: TestShellSplit (0.00s)195--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)196=== CONT TestStreamPushReportsEveryPath197=== CONT TestClientSignaturesByStorePath198=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths199=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths200=== RUN TestParsePathInfoJSON/Lix_format201=== PAUSE TestParsePathInfoJSON/Lix_format202=== RUN TestParsePathInfoJSON/empty_input203=== PAUSE TestParsePathInfoJSON/empty_input204=== RUN TestParsePathInfoJSON/whitespace_only205=== PAUSE TestParsePathInfoJSON/whitespace_only206=== RUN TestParsePathInfoJSON/invalid_JSON207=== PAUSE TestParsePathInfoJSON/invalid_JSON208=== CONT TestStreamPushGivesUpOnDeadServer209=== CONT TestPathInfoCACompatibility/new_structured_format_-_text210=== CONT TestDumpPathWriterError2112026/10/01 09:42:24 ERROR Upload failed error="connection refused" count=202122026/10/01 09:42:24 ERROR Server seems unavailable, giving up on batch untried=17213=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method214=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive215=== CONT TestPathInfoCACompatibility/old_string_format_-_text216=== CONT TestEncodeNixBase32/test_string_hash217=== CONT TestEncodeNixBase32/empty_input218=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths219=== CONT TestParsePathInfoJSON/Nix_format220=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths221=== CONT TestParsePathInfoJSON/invalid_JSON222=== CONT TestParsePathInfoJSON/whitespace_only223=== CONT TestParsePathInfoJSON/empty_input224=== CONT TestParsePathInfoJSON/Lix_format225=== RUN TestSetClientTLSErrors/missing_cert_file226=== PAUSE TestSetClientTLSErrors/missing_cert_file227=== RUN TestSetClientTLSErrors/missing_key_file228=== PAUSE TestSetClientTLSErrors/missing_key_file229=== RUN TestSetClientTLSErrors/missing_ca_file230=== PAUSE TestSetClientTLSErrors/missing_ca_file231=== RUN TestSetClientTLSErrors/invalid_ca_file232=== PAUSE TestSetClientTLSErrors/invalid_ca_file233=== CONT TestSetClientTLSErrors/missing_cert_file234=== CONT TestSetClientTLSErrors/invalid_ca_file235=== CONT TestSetClientTLSErrors/missing_ca_file236=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error237=== RUN TestConvertHashToNix32/already_Nix32_format238=== RUN TestUploadMultipart_SupersededByPeer/missing239=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter240=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum241=== RUN TestFilterOversizedClosures/all_closures_skipped242=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)243--- PASS: TestClientSignaturesByStorePath (0.00s)244=== CONT TestStreamPushRequestLine245=== CONT TestPathInfoCACompatibility/null_ca_field246=== CONT TestRateLimiterFeedback/429_enables_limiter247=== CONT TestSetClientTLSErrors/missing_key_file248=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum249=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts250=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts251=== RUN TestPartSizeForNAR/1_TiB252=== PAUSE TestPartSizeForNAR/1_TiB253=== RUN TestPartSizeForNAR/5_TiB_S3_max_object254=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object255=== CONT TestRateLimiterFeedback/503_enables_limiter256--- PASS: TestStreamPushIsolatesFailures (0.00s)257--- PASS: TestStreamPushReportsEveryPath (0.00s)258--- PASS: TestResolveStorePath (0.00s)259--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)260=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error261=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error262=== CONT TestGetStorePathHash/valid_store_path263=== PAUSE TestConvertHashToNix32/already_Nix32_format264=== RUN TestConvertHashToNix32/invalid_format265=== PAUSE TestConvertHashToNix32/invalid_format266=== CONT TestConvertHashToNix32/SRI_format_to_Nix32267=== RUN TestPartSizeForNAR/capped_at_5_GiB268=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error269=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter270=== CONT TestConvertHashToNix32/invalid_format271=== CONT TestGetStorePathHash/basename_without_hyphen_should_error272=== RUN TestSetClientTLS/rejects_connection_without_client_cert273=== CONT TestConvertHashToNix32/already_Nix32_format274=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert275=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA276=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA277=== RUN TestSetClientTLS/preserves_debug_logging_transport278=== PAUSE TestSetClientTLS/preserves_debug_logging_transport279=== CONT TestSetClientTLS/rejects_connection_without_client_cert280=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2812026/10/01 09:42:24 WARN Rate limiter enabled after throttle name=server-test rate=5282--- PASS: TestEncodeNixBase32 (0.03s)283 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)284 --- PASS: TestEncodeNixBase32/empty_input (0.00s)2852026/10/01 09:42:24 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34623286=== PAUSE TestPartSizeForNAR/capped_at_5_GiB287=== CONT TestSetClientTLS/preserves_debug_logging_transport288=== PAUSE TestUploadMultipart_SupersededByPeer/missing289=== PAUSE TestFilterOversizedClosures/all_closures_skipped290=== CONT TestPartSizeForNAR/5_TiB_S3_max_object291=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts292=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum293=== CONT TestPartSizeForNAR/small_stays_at_minimum2942026/10/01 09:42:24 WARN Rate limiter enabled after throttle name=server-test rate=5295=== CONT TestUploadMultipart_SupersededByPeer/exists2962026/10/01 09:42:24 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:448932972026/10/01 09:42:24 ERROR Upload failed error=boom count=1298=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2992026/10/01 09:42:24 WARN Rate limiter backed off name=server-test rate=5300=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon301=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon302=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI303=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI304=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512305=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512306=== CONT TestPartSizeForNAR/zero_stays_at_minimum307=== CONT TestUploadMultipart_SupersededByPeer/missing308--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)309 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)310 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)311--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)312--- PASS: TestConvertHashToNix32 (0.00s)313 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)314 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)315 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)316=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)317=== CONT TestFilterOversizedClosures/all_closures_skipped318--- PASS: TestPathInfoCACompatibility (0.03s)319 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)320 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)321 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)322 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)323 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)3242026/10/01 09:42:24 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50325--- PASS: TestParsePathInfoJSON (0.00s)326 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)327 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)328 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)329 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)330 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)331=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3322026/10/01 09:42:24 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000333=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512334=== CONT TestPartSizeForNAR/1_TiB335=== CONT TestFilterOversizedClosures/no_limit_keeps_everything336--- PASS: TestFilterOversizedClosures (0.04s)337 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)338 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)339 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)340=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error341=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon342=== CONT TestPartSizeForNAR/capped_at_5_GiB343--- PASS: TestPartSizeForNAR (0.04s)344 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)345 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)346 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)347 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)348 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)349 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)350 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)351=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI3522026/10/01 09:42:24 WARN Rate limiter backed off name=server-test rate=5353--- PASS: TestSetClientTLSErrors (0.00s)354 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)355 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)356 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)357 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)358--- PASS: TestPathInfoHashCompatibility (0.03s)359 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)360 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)361 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)362 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)363--- PASS: TestGetStorePathHash (0.00s)364 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)365 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)366 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)367 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)368--- PASS: TestRateLimiterFeedback (0.04s)369 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)370 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)371 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)373--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)374 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)375 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)376=== CONT TestStreamPushReportsSignatures377--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)3782026/10/01 09:42:24 ERROR Upload failed error=boom count=1379--- PASS: TestStreamPushReportsSignatures (0.00s)3802026/10/01 09:42:24 http: TLS handshake error from 127.0.0.1:52786: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.00s)382 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)385--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)386--- PASS: TestDumpPathSingleFile (0.03s)387--- PASS: TestCaseHackSuffix (0.03s)388--- PASS: TestStreamPushRequestLine (0.04s)389--- PASS: TestDumpPathWriterError (0.04s)390--- PASS: TestDumpPathMatchesNix (0.08s)391--- PASS: TestStreamPushBatchesUnderLoad (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres3465603415/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres3465603415/data -l logfile start422423/build/postgres3465603415:5432 - no response4242026-10-01 09:42:26.335 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 09:42:26.336 UTC [129] LOG: listening on Unix socket "/build/postgres3465603415/.s.PGSQL.5432"4262026-10-01 09:42:26.340 UTC [136] LOG: database system was shut down at 2026-10-01 09:42:26 UTC4272026-10-01 09:42:26.344 UTC [129] LOG: database system is ready to accept connections428/build/postgres3465603415:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock466=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestLeadElectsOneAndHandsOver470=== PAUSE TestLeadElectsOneAndHandsOver471=== RUN TestLeadIncumbentWinsAfterRestart4722026-10-01 09:42:26.715 UTC [374] ERROR: relation "goose_db_version" does not exist at character 364732026-10-01 09:42:26.715 UTC [374] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4742026/10/01 09:42:26 OK 20241026095416_initial_model.sql (10.09ms)4752026/10/01 09:42:26 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)4762026/10/01 09:42:26 OK 20251218171726_add_pins.sql (2.74ms)4772026/10/01 09:42:26 OK 20260628120000_add_object_size_and_stats.sql (2.45ms)4782026/10/01 09:42:26 OK 20260905000000_add_claims.sql (2.89ms)4792026/10/01 09:42:26 OK 20260920000000_drop_claims.sql (1.74ms)4802026/10/01 09:42:26 OK 20260923120000_add_pushes.sql (1.38ms)4812026/10/01 09:42:26 goose: successfully migrated database to version: 202609231200004822026/10/01 09:42:26 OK 1_commit_pending_closure.sql (1.61ms)4832026/10/01 09:42:26 OK 2_object_stats_trigger.sql (696.43µs)4842026/10/01 09:42:26 OK 3_commit_push.sql (529.49µs)4852026/10/01 09:42:26 goose: up to current file version: 34862026/10/01 09:42:26 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 09:42:27 INFO lead: released remote=192.0.2.1:12344882026/10/01 09:42:27 INFO lead: acquired remote=192.0.2.1:12344892026/10/01 09:42:27 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (0.78s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestGCAdvisoryLockBlocksConcurrentRun4942026-10-01 09:42:27.473 UTC [385] ERROR: relation "goose_db_version" does not exist at character 364952026-10-01 09:42:27.473 UTC [385] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4962026/10/01 09:42:27 OK 20241026095416_initial_model.sql (8.59ms)4972026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)4982026/10/01 09:42:27 OK 20251218171726_add_pins.sql (2.82ms)4992026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (2.78ms)5002026/10/01 09:42:27 OK 20260905000000_add_claims.sql (2.68ms)5012026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (1.63ms)5022026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (1.18ms)5032026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200005042026/10/01 09:42:27 OK 1_commit_pending_closure.sql (1.82ms)5052026/10/01 09:42:27 OK 2_object_stats_trigger.sql (699.11µs)5062026/10/01 09:42:27 OK 3_commit_push.sql (534.42µs)5072026/10/01 09:42:27 goose: up to current file version: 3508--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)509=== RUN TestGCBugBareHashReferences510=== PAUSE TestGCBugBareHashReferences511=== RUN TestGCMetrics512=== PAUSE TestGCMetrics513=== RUN TestPushDedupSurvivesConcurrentGC514=== PAUSE TestPushDedupSurvivesConcurrentGC515=== RUN TestDeduplicatedObjectsRecordedAsPending516=== PAUSE TestDeduplicatedObjectsRecordedAsPending517=== RUN TestGCSweepSkipsPendingObjects518=== PAUSE TestGCSweepSkipsPendingObjects519=== RUN TestTombstonedObjectOfferedWithoutWaiting520=== PAUSE TestTombstonedObjectOfferedWithoutWaiting521=== RUN TestGCSweepDeliversEachKeyOnce522=== PAUSE TestGCSweepDeliversEachKeyOnce523=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== RUN TestForceGCDuringPushOffersSweptObject526=== PAUSE TestForceGCDuringPushOffersSweptObject527=== RUN TestFailedS3DeleteKeepsTombstone528=== PAUSE TestFailedS3DeleteKeepsTombstone529=== RUN TestSweepSkipsRowsLockedByPush530=== PAUSE TestSweepSkipsRowsLockedByPush531=== RUN TestRegisterCompletedObjectNeedsPendingRow532=== PAUSE TestRegisterCompletedObjectNeedsPendingRow533=== RUN TestGetExistingObjectsLocksRows534=== PAUSE TestGetExistingObjectsLocksRows535=== RUN TestSweepRechecksPendingAfterLocking536=== PAUSE TestSweepRechecksPendingAfterLocking537=== RUN TestPushWaitsForSweepHoldingRow538=== PAUSE TestPushWaitsForSweepHoldingRow539=== RUN TestCommitRacingPendingCleanupKeepsObjects540=== PAUSE TestCommitRacingPendingCleanupKeepsObjects541=== RUN TestGCEndsOnShutdown542=== PAUSE TestGCEndsOnShutdown543=== RUN TestGCTaskStore_StartNew544=== PAUSE TestGCTaskStore_StartNew545=== RUN TestGCTaskStore_DeduplicateSameParams546=== PAUSE TestGCTaskStore_DeduplicateSameParams547=== RUN TestGCTaskStore_ConflictDifferentParams548=== PAUSE TestGCTaskStore_ConflictDifferentParams549=== RUN TestGCTaskStore_GetEmpty550=== PAUSE TestGCTaskStore_GetEmpty551=== RUN TestGCTaskStore_GetReturnsLatest552=== PAUSE TestGCTaskStore_GetReturnsLatest553=== RUN TestGCTaskStore_CompletedAllowsNewTask554=== PAUSE TestGCTaskStore_CompletedAllowsNewTask555=== RUN TestGCTaskStore_PhaseUpdates556=== PAUSE TestGCTaskStore_PhaseUpdates557=== RUN TestGCTaskStore_Fail558=== PAUSE TestGCTaskStore_Fail559=== RUN TestGracefulShutdownDrainsInflight560=== PAUSE TestGracefulShutdownDrainsInflight561=== RUN TestService_healthCheckHandler562=== PAUSE TestService_healthCheckHandler563=== RUN TestService_readinessHandler564=== PAUSE TestService_readinessHandler565=== RUN TestGenerateLandingPage566=== PAUSE TestGenerateLandingPage567=== RUN TestCacheConfigHandlerMaxNarSize568=== PAUSE TestCacheConfigHandlerMaxNarSize569=== RUN TestCreatePendingClosureRejectsOversizedNAR570=== PAUSE TestCreatePendingClosureRejectsOversizedNAR571=== RUN TestNARDeduplicationMetadataUploadBug572=== PAUSE TestNARDeduplicationMetadataUploadBug573=== RUN TestMetricsInventory574=== PAUSE TestMetricsInventory575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentNotReportedWhileGCDeletesClosure592=== PAUSE TestPresentNotReportedWhileGCDeletesClosure593=== RUN TestParseSingleRange594=== PAUSE TestParseSingleRange595=== RUN TestProxyHeadersOnlyTrustedOnSocket596=== PAUSE TestProxyHeadersOnlyTrustedOnSocket597=== RUN TestIsValidCachePath598=== PAUSE TestIsValidCachePath599=== RUN TestReadProxyNarinfo600=== PAUSE TestReadProxyNarinfo601=== RUN TestReadProxyNarinfoAlreadyDecompressed602=== PAUSE TestReadProxyNarinfoAlreadyDecompressed603=== RUN TestReadProxyNarStreaming604=== PAUSE TestReadProxyNarStreaming605=== RUN TestReadProxy404606=== PAUSE TestReadProxy404607=== RUN TestReadProxyInvalidPath608=== PAUSE TestReadProxyInvalidPath609=== RUN TestReadProxyHead610=== PAUSE TestReadProxyHead611=== RUN TestReadProxyConditionalGet612=== PAUSE TestReadProxyConditionalGet613=== RUN TestReadProxyRootRedirectsToIndexHTML614=== PAUSE TestReadProxyRootRedirectsToIndexHTML615=== RUN TestReadProxyDisabled616=== PAUSE TestReadProxyDisabled617=== RUN TestReadRedirectNar618=== PAUSE TestReadRedirectNar619=== RUN TestReadRedirectKeepsNarinfoProxied620=== PAUSE TestReadRedirectKeepsNarinfoProxied621=== RUN TestReadProxyRangeRequest622=== PAUSE TestReadProxyRangeRequest623=== RUN TestReadRedirectUsesPublicS3URL624=== PAUSE TestReadRedirectUsesPublicS3URL625=== RUN TestPush_OverlappingRootsStoreOneRowPerKey626=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey627=== RUN TestPush_CompleteCommitsEveryRoot628=== PAUSE TestPush_CompleteCommitsEveryRoot629=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit630=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit631=== RUN TestPush_RejectsBadRequests632=== PAUSE TestPush_RejectsBadRequests633=== RUN TestPush_SignsNarinfosOfItsPendingObjects634=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects635=== RUN TestRedundantMultipartUpload636=== PAUSE TestRedundantMultipartUpload637=== RUN TestCompleteMultipartUpload_ErrorButObjectExists638=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists639=== RUN TestCompletedNarNotReofferedAcrossClosures640=== PAUSE TestCompletedNarNotReofferedAcrossClosures641=== RUN TestPresignedUploadRegisteredBeforeCommit642=== PAUSE TestPresignedUploadRegisteredBeforeCommit643=== RUN TestService_Rustfstest644=== PAUSE TestService_Rustfstest645=== RUN TestParseSize646=== PAUSE TestParseSize647=== RUN TestSkippedUploadsHandler648=== PAUSE TestSkippedUploadsHandler649=== RUN TestSystemdListenerNotActivated650--- PASS: TestSystemdListenerNotActivated (0.00s)651=== RUN TestWatchdogBeatsWhenHealthy652--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)653=== RUN TestWatchdogSkipsWhenUnhealthy6542026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 09:42:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"664--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)665=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle666=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle667=== RUN TestProxyWriteTimeout668=== PAUSE TestProxyWriteTimeout669=== RUN TestIsValidUploadKey670=== PAUSE TestIsValidUploadKey671=== RUN TestUploadHandlersRejectInvalidKeys672=== PAUSE TestUploadHandlersRejectInvalidKeys673=== RUN TestUploadHandlersRejectOversizedBody674=== PAUSE TestUploadHandlersRejectOversizedBody675=== RUN TestService_cleanupPendingClosuresHandler676=== PAUSE TestService_cleanupPendingClosuresHandler677=== RUN TestService_createPendingClosureHandler678=== PAUSE TestService_createPendingClosureHandler679=== RUN TestService_verifyS3Integrity680=== PAUSE TestService_verifyS3Integrity681=== RUN TestCompleteMultipartUnregistered682=== PAUSE TestCompleteMultipartUnregistered683=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT684=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT685=== CONT TestProxyWriteTimeout686=== CONT TestParseSize687=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT688=== RUN TestProxyWriteTimeout/narinfo689=== PAUSE TestProxyWriteTimeout/narinfo690=== CONT TestService_AuthMiddleware691=== CONT TestService_createPendingClosureHandler692=== CONT TestUploadHandlersRejectOversizedBody693=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle694=== CONT TestSkippedUploadsHandler695=== CONT TestService_cleanupPendingClosuresHandler696=== CONT TestGCTaskStore_PhaseUpdates697--- PASS: TestParseSize (0.00s)698--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)699=== CONT TestService_Rustfstest700=== CONT TestPresignedUploadRegisteredBeforeCommit701=== CONT TestGCTaskStore_CompletedAllowsNewTask702=== CONT TestCompletedNarNotReofferedAcrossClosures703=== CONT TestGCTaskStore_GetReturnsLatest704=== CONT TestCompleteMultipartUpload_ErrorButObjectExists705=== CONT TestRedundantMultipartUpload706=== CONT TestPush_SignsNarinfosOfItsPendingObjects707=== CONT TestPush_RejectsBadRequests708=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit709=== CONT TestPush_CompleteCommitsEveryRoot710=== CONT TestPush_OverlappingRootsStoreOneRowPerKey711=== CONT TestReadRedirectUsesPublicS3URL712=== CONT TestReadProxyRangeRequest713=== CONT TestGCTaskStore_GetEmpty714=== RUN TestProxyWriteTimeout/1_GiB_nar715=== CONT TestReadRedirectKeepsNarinfoProxied7162026/10/01 09:42:27 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000717--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)718--- PASS: TestGCTaskStore_GetEmpty (0.00s)719=== CONT TestLeadEndsOnShutdown720--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)721=== CONT TestLeadElectsOneAndHandsOver722=== CONT TestGCTaskStore_ConflictDifferentParams723--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)724=== CONT TestGCTaskStore_DeduplicateSameParams725--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)726=== CONT TestGCTaskStore_StartNew727--- PASS: TestGCTaskStore_StartNew (0.00s)728=== CONT TestGCEndsOnShutdown729=== PAUSE TestProxyWriteTimeout/1_GiB_nar730=== RUN TestProxyWriteTimeout/10_GiB_nar731=== PAUSE TestProxyWriteTimeout/10_GiB_nar732=== RUN TestProxyWriteTimeout/unknown_size733=== PAUSE TestProxyWriteTimeout/unknown_size734=== CONT TestCommitRacingPendingCleanupKeepsObjects735--- PASS: TestSkippedUploadsHandler (0.08s)736=== CONT TestPushWaitsForSweepHoldingRow7372026-10-01 09:42:27.902 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367382026-10-01 09:42:27.902 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7392026-10-01 09:42:27.902 UTC [450] ERROR: relation "goose_db_version" does not exist at character 367402026-10-01 09:42:27.902 UTC [450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7412026-10-01 09:42:27.903 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367422026-10-01 09:42:27.903 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7432026-10-01 09:42:27.905 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367442026-10-01 09:42:27.905 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7452026-10-01 09:42:27.907 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367462026-10-01 09:42:27.907 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7472026-10-01 09:42:27.908 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367482026-10-01 09:42:27.908 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7492026-10-01 09:42:27.912 UTC [455] ERROR: relation "goose_db_version" does not exist at character 367502026-10-01 09:42:27.912 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC751=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure752=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure753=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart754=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart755=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts756=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts757=== CONT TestResolveDBConnectionString758=== RUN TestResolveDBConnectionString/flag_wins759=== PAUSE TestResolveDBConnectionString/flag_wins760=== RUN TestResolveDBConnectionString/file_when_flag_empty761=== PAUSE TestResolveDBConnectionString/file_when_flag_empty762=== RUN TestResolveDBConnectionString/missing_file_is_an_error763=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error764=== RUN TestResolveDBConnectionString/PGHOST_allows_empty765=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty766=== RUN TestResolveDBConnectionString/nothing_configured767=== PAUSE TestResolveDBConnectionString/nothing_configured768=== CONT TestSweepRechecksPendingAfterLocking7692026-10-01 09:42:27.913 UTC [456] ERROR: relation "goose_db_version" does not exist at character 367702026-10-01 09:42:27.913 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026-10-01 09:42:27.923 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367722026-10-01 09:42:27.923 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026-10-01 09:42:27.924 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367742026-10-01 09:42:27.924 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7752026/10/01 09:42:27 OK 20241026095416_initial_model.sql (25.76ms)7762026/10/01 09:42:27 OK 20241026095416_initial_model.sql (26ms)7772026/10/01 09:42:27 OK 20241026095416_initial_model.sql (22.48ms)7782026-10-01 09:42:27.948 UTC [461] ERROR: relation "goose_db_version" does not exist at character 367792026-10-01 09:42:27.948 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7802026-10-01 09:42:27.949 UTC [464] ERROR: relation "goose_db_version" does not exist at character 367812026-10-01 09:42:27.949 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7822026/10/01 09:42:27 OK 20241026095416_initial_model.sql (32.36ms)7832026/10/01 09:42:27 OK 20241026095416_initial_model.sql (33.37ms)7842026/10/01 09:42:27 OK 20241026095416_initial_model.sql (31.38ms)7852026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (8.86ms)7862026/10/01 09:42:27 OK 20241026095416_initial_model.sql (34.04ms)7872026/10/01 09:42:27 OK 20241026095416_initial_model.sql (34.09ms)7882026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (10.9ms)7892026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (4.81ms)7902026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (11.01ms)7912026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (6.59ms)7922026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (4.81ms)7932026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)7942026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)7952026/10/01 09:42:27 OK 20251218171726_add_pins.sql (6.87ms)7962026/10/01 09:42:27 OK 20251218171726_add_pins.sql (4.81ms)7972026/10/01 09:42:27 OK 20251218171726_add_pins.sql (5.51ms)7982026/10/01 09:42:27 OK 20251218171726_add_pins.sql (4.27ms)7992026/10/01 09:42:27 OK 20251218171726_add_pins.sql (5.67ms)8002026/10/01 09:42:27 OK 20251218171726_add_pins.sql (5.74ms)8012026/10/01 09:42:27 OK 20251218171726_add_pins.sql (5.6ms)8022026/10/01 09:42:27 OK 20251218171726_add_pins.sql (5.59ms)8032026/10/01 09:42:27 OK 20241026095416_initial_model.sql (24.23ms)8042026/10/01 09:42:27 OK 20241026095416_initial_model.sql (25.13ms)8052026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)8062026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (6.09ms)8072026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (6.23ms)8082026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (4.97ms)8092026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (5.3ms)8102026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (5.2ms)8112026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (11.6ms)8122026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (8.22ms)8132026/10/01 09:42:27 OK 20260905000000_add_claims.sql (8.13ms)8142026/10/01 09:42:27 OK 20260905000000_add_claims.sql (8.15ms)8152026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (12.81ms)8162026/10/01 09:42:27 OK 20260905000000_add_claims.sql (8.2ms)8172026/10/01 09:42:27 OK 20251218171726_add_pins.sql (8.69ms)8182026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (12.44ms)8192026/10/01 09:42:27 OK 20241026095416_initial_model.sql (20.05ms)8202026/10/01 09:42:27 OK 20260905000000_add_claims.sql (8.08ms)8212026/10/01 09:42:27 OK 20260905000000_add_claims.sql (8.05ms)8222026-10-01 09:42:27.979 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368232026-10-01 09:42:27.979 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026-10-01 09:42:27.979 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368252026-10-01 09:42:27.979 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.5ms)8272026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.17ms)8282026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.71ms)8292026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.62ms)8302026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (3.51ms)8312026/10/01 09:42:27 OK 20260905000000_add_claims.sql (6.5ms)8322026/10/01 09:42:27 OK 20260905000000_add_claims.sql (4.49ms)8332026/10/01 09:42:27 OK 20241026095416_initial_model.sql (19.57ms)8342026/10/01 09:42:27 OK 20251218171726_add_pins.sql (6.32ms)8352026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (4.44ms)8362026/10/01 09:42:27 OK 20260905000000_add_claims.sql (5.22ms)8372026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (6.07ms)8382026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (3.36ms)8392026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200008402026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (3.38ms)8412026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200008422026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (3.5ms)8432026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200008442026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (3.33ms)8452026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200008462026/10/01 09:42:27 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)8472026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (2.87ms)8482026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200008492026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.68ms)8502026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.86ms)8512026/10/01 09:42:27 OK 20251218171726_add_pins.sql (4.78ms)8522026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)8532026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.42ms)8542026/10/01 09:42:27 OK 20260905000000_add_claims.sql (3.35ms)8552026/10/01 09:42:27 OK 1_commit_pending_closure.sql (3.26ms)8562026/10/01 09:42:27 OK 1_commit_pending_closure.sql (3.47ms)8572026-10-01 09:42:27.986 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368582026-10-01 09:42:27.986 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8592026/10/01 09:42:27 OK 1_commit_pending_closure.sql (3.12ms)8602026/10/01 09:42:27 OK 1_commit_pending_closure.sql (3.35ms)8612026/10/01 09:42:27 OK 1_commit_pending_closure.sql (3.71ms)8622026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (2.96ms)8632026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200008642026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (3.09ms)8652026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200008662026/10/01 09:42:27 OK 20251218171726_add_pins.sql (4.09ms)8672026/10/01 09:42:27 OK 2_object_stats_trigger.sql (1.65ms)8682026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (2.95ms)8692026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200008702026-10-01 09:42:27.989 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368712026-10-01 09:42:27.989 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8722026/10/01 09:42:27 OK 2_object_stats_trigger.sql (2.46ms)8732026/10/01 09:42:27 OK 2_object_stats_trigger.sql (2.51ms)8742026/10/01 09:42:27 OK 2_object_stats_trigger.sql (2.42ms)8752026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.37ms)8762026-10-01 09:42:27.989 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368772026-10-01 09:42:27.989 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8782026/10/01 09:42:27 OK 20260905000000_add_claims.sql (4.5ms)8792026/10/01 09:42:27 OK 3_commit_push.sql (2.37ms)8802026/10/01 09:42:27 goose: up to current file version: 38812026/10/01 09:42:27 OK 2_object_stats_trigger.sql (2.57ms)8822026/10/01 09:42:27 OK 1_commit_pending_closure.sql (2.93ms)8832026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)8842026/10/01 09:42:27 OK 3_commit_push.sql (1.88ms)8852026/10/01 09:42:27 goose: up to current file version: 38862026/10/01 09:42:27 OK 3_commit_push.sql (2.07ms)8872026/10/01 09:42:27 goose: up to current file version: 38882026/10/01 09:42:27 OK 1_commit_pending_closure.sql (3.47ms)8892026/10/01 09:42:27 OK 3_commit_push.sql (2.02ms)8902026/10/01 09:42:27 goose: up to current file version: 38912026/10/01 09:42:27 OK 1_commit_pending_closure.sql (2.96ms)8922026/10/01 09:42:27 OK 2_object_stats_trigger.sql (1.65ms)8932026/10/01 09:42:27 OK 3_commit_push.sql (1.71ms)8942026/10/01 09:42:27 goose: up to current file version: 38952026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (3.08ms)8962026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200008972026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.01ms)8982026/10/01 09:42:27 OK 2_object_stats_trigger.sql (1.62ms)8992026/10/01 09:42:27 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)9002026/10/01 09:42:27 OK 2_object_stats_trigger.sql (2.15ms)9012026/10/01 09:42:27 OK 20260905000000_add_claims.sql (3.59ms)9022026/10/01 09:42:27 OK 3_commit_push.sql (1.96ms)9032026/10/01 09:42:27 goose: up to current file version: 39042026-10-01 09:42:27.995 UTC [470] ERROR: relation "goose_db_version" does not exist at character 369052026-10-01 09:42:27.995 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9062026-10-01 09:42:27.995 UTC [471] ERROR: relation "goose_db_version" does not exist at character 369072026-10-01 09:42:27.995 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9082026/10/01 09:42:27 OK 3_commit_push.sql (2.56ms)9092026/10/01 09:42:27 goose: up to current file version: 39102026/10/01 09:42:27 OK 1_commit_pending_closure.sql (3.59ms)9112026/10/01 09:42:27 OK 20260923120000_add_pushes.sql (3.52ms)9122026/10/01 09:42:27 goose: successfully migrated database to version: 202609231200009132026/10/01 09:42:27 OK 20241026095416_initial_model.sql (10.73ms)9142026-10-01 09:42:27.996 UTC [472] ERROR: relation "goose_db_version" does not exist at character 369152026-10-01 09:42:27.996 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9162026/10/01 09:42:27 OK 3_commit_push.sql (2.64ms)9172026/10/01 09:42:27 goose: up to current file version: 39182026-10-01 09:42:27.996 UTC [473] ERROR: relation "goose_db_version" does not exist at character 369192026-10-01 09:42:27.996 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9202026/10/01 09:42:27 OK 20260920000000_drop_claims.sql (3.5ms)9212026/10/01 09:42:27 OK 2_object_stats_trigger.sql (2.11ms)9222026-10-01 09:42:27.998 UTC [474] ERROR: relation "goose_db_version" does not exist at character 369232026-10-01 09:42:27.998 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9242026-10-01 09:42:27.999 UTC [475] ERROR: relation "goose_db_version" does not exist at character 369252026-10-01 09:42:27.999 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9262026/10/01 09:42:28 OK 1_commit_pending_closure.sql (3.36ms)9272026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)9282026/10/01 09:42:28 OK 20241026095416_initial_model.sql (13.33ms)9292026/10/01 09:42:28 OK 20260905000000_add_claims.sql (7.22ms)9302026/10/01 09:42:28 OK 3_commit_push.sql (1.89ms)9312026/10/01 09:42:28 goose: up to current file version: 39322026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (3.22ms)9332026/10/01 09:42:28 goose: successfully migrated database to version: 202609231200009342026/10/01 09:42:28 OK 2_object_stats_trigger.sql (2.16ms)9352026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)9362026/10/01 09:42:28 OK 3_commit_push.sql (1.68ms)9372026/10/01 09:42:28 goose: up to current file version: 39382026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.67ms)9392026/10/01 09:42:28 OK 1_commit_pending_closure.sql (3.12ms)9402026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (4.19ms)9412026/10/01 09:42:28 OK 20241026095416_initial_model.sql (11.15ms)9422026/10/01 09:42:28 OK 2_object_stats_trigger.sql (2.35ms)9432026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.64ms)9442026/10/01 09:42:28 OK 20241026095416_initial_model.sql (13.71ms)9452026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.89ms)9462026/10/01 09:42:28 goose: successfully migrated database to version: 202609231200009472026/10/01 09:42:28 OK 20241026095416_initial_model.sql (11.33ms)9482026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)9492026/10/01 09:42:28 OK 3_commit_push.sql (1.96ms)9502026/10/01 09:42:28 goose: up to current file version: 39512026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)9522026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)9532026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)9542026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.71ms)9552026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.2ms)9562026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.3ms)9572026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)9582026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.96ms)9592026/10/01 09:42:28 OK 20260905000000_add_claims.sql (4.05ms)9602026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.78ms)9612026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)9622026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.73ms)9632026/10/01 09:42:28 OK 3_commit_push.sql (1.3ms)9642026/10/01 09:42:28 goose: up to current file version: 39652026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures9662026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.45ms)9672026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)9682026/10/01 09:42:28 OK 20241026095416_initial_model.sql (9.87ms)9692026/10/01 09:42:28 OK 20241026095416_initial_model.sql (12.96ms)9702026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.14ms)9712026/10/01 09:42:28 OK 20260905000000_add_claims.sql (4.44ms)9722026/10/01 09:42:28 OK 20241026095416_initial_model.sql (9.78ms)9732026/10/01 09:42:28 OK 20241026095416_initial_model.sql (13.11ms)9742026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.22ms)9752026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)9762026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)9772026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)9782026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)9792026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)9802026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.62ms)9812026/10/01 09:42:28 goose: successfully migrated database to version: 202609231200009822026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.33ms)9832026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)9842026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)9852026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.22ms)9862026/10/01 09:42:28 OK 20260905000000_add_claims.sql (2.98ms)9872026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.69ms)9882026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.42ms)9892026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.65ms)9902026/10/01 09:42:28 OK 1_commit_pending_closure.sql (3.01ms)9912026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.51ms)9922026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.42ms)9932026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.93ms)9942026/10/01 09:42:28 goose: successfully migrated database to version: 202609231200009952026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.42ms)9962026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.95ms)9972026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.6ms)9982026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.78ms)9992026/10/01 09:42:28 OK 20260905000000_add_claims.sql (2.68ms)10002026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.2ms)10012026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.43ms)10022026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.19ms)10032026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.67ms)10042026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.44ms)10052026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010062026/10/01 09:42:28 OK 3_commit_push.sql (2.37ms)10072026/10/01 09:42:28 goose: up to current file version: 310082026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (3.16ms)10092026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010102026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)10112026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)10122026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4ms)10132026-10-01 09:42:28.026 UTC [476] ERROR: relation "goose_db_version" does not exist at character 3610142026-10-01 09:42:28.026 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10152026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.87ms)10162026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010172026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)10182026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.06ms)10192026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.51ms)10202026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.26ms)10212026/10/01 09:42:28 OK 3_commit_push.sql (1.37ms)10222026/10/01 09:42:28 goose: up to current file version: 310232026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.67ms)10242026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.55ms)10252026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.75ms)10262026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.45ms)10272026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010282026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.18ms)10292026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.32ms)10302026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.27ms)10312026/10/01 09:42:28 OK 2_object_stats_trigger.sql (913.13µs)10322026/10/01 09:42:28 OK 2_object_stats_trigger.sql (963.15µs)10332026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.98ms)10342026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.52ms)10352026/10/01 09:42:28 OK 2_object_stats_trigger.sql (913.57µs)10362026/10/01 09:42:28 OK 3_commit_push.sql (897.55µs)10372026/10/01 09:42:28 goose: up to current file version: 310382026/10/01 09:42:28 OK 3_commit_push.sql (975.55µs)10392026/10/01 09:42:28 goose: up to current file version: 310402026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (1.61ms)10412026/10/01 09:42:28 OK 1_commit_pending_closure.sql (1.93ms)10422026/10/01 09:42:28 OK 3_commit_push.sql (1.09ms)10432026/10/01 09:42:28 goose: up to current file version: 310442026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.12ms)10452026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (1.82ms)10462026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010472026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.39ms)10482026/10/01 09:42:28 OK 2_object_stats_trigger.sql (842.05µs)10492026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.05ms)10502026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (1.45ms)10512026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010522026/10/01 09:42:28 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1053--- PASS: TestService_AuthMiddleware (0.28s)1054=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10552026/10/01 09:42:28 OK 3_commit_push.sql (650.83µs)10562026/10/01 09:42:28 goose: up to current file version: 310572026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (1.56ms)10582026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010592026/10/01 09:42:28 OK 1_commit_pending_closure.sql (1.57ms)10602026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (1.68ms)10612026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010622026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (1.74ms)10632026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010642026/10/01 09:42:28 OK 1_commit_pending_closure.sql (1.57ms)10652026/10/01 09:42:28 OK 2_object_stats_trigger.sql (826.81µs)10662026/10/01 09:42:28 OK 1_commit_pending_closure.sql (1.64ms)10672026/10/01 09:42:28 OK 2_object_stats_trigger.sql (880.55µs)10682026/10/01 09:42:28 OK 3_commit_push.sql (719.83µs)10692026/10/01 09:42:28 goose: up to current file version: 310702026/10/01 09:42:28 OK 1_commit_pending_closure.sql (1.8ms)10712026/10/01 09:42:28 OK 2_object_stats_trigger.sql (804.15µs)10722026/10/01 09:42:28 OK 3_commit_push.sql (652.39µs)10732026/10/01 09:42:28 goose: up to current file version: 310742026/10/01 09:42:28 OK 1_commit_pending_closure.sql (1.81ms)10752026/10/01 09:42:28 OK 2_object_stats_trigger.sql (850.01µs)10762026/10/01 09:42:28 OK 2_object_stats_trigger.sql (956.99µs)10772026/10/01 09:42:28 OK 3_commit_push.sql (886.27µs)10782026/10/01 09:42:28 goose: up to current file version: 310792026/10/01 09:42:28 OK 3_commit_push.sql (723.29µs)10802026/10/01 09:42:28 goose: up to current file version: 310812026/10/01 09:42:28 OK 3_commit_push.sql (580.47µs)10822026/10/01 09:42:28 goose: up to current file version: 310832026/10/01 09:42:28 OK 20241026095416_initial_model.sql (7.8ms)10842026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)10852026/10/01 09:42:28 OK 20251218171726_add_pins.sql (2.68ms)10862026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (2.79ms)10872026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures10882026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures10892026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures10902026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.14ms)10912026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (1.55ms)10922026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (1.74ms)10932026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000010942026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.27ms)10952026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.44ms)10962026/10/01 09:42:28 OK 3_commit_push.sql (1.48ms)10972026/10/01 09:42:28 goose: up to current file version: 310982026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures1099--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.32s)1100=== CONT TestReadRedirectNar11012026/10/01 09:42:28 INFO Received cleanup request method=DELETE path=/api/pending_closures11022026/10/01 09:42:28 INFO Aborted multipart uploads count=0 kept=011032026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures11042026/10/01 09:42:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11052026-10-01 09:42:28.100 UTC [483] ERROR: relation "goose_db_version" does not exist at character 3611062026-10-01 09:42:28.100 UTC [483] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11072026/10/01 09:42:28 INFO Received cleanup request method=DELETE path=/api/pending_closures11082026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures11092026/10/01 09:42:28 INFO Aborted multipart uploads count=1 kept=011102026/10/01 09:42:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11112026-10-01 09:42:28.108 UTC [451] ERROR: Closure does not exist: id=111122026-10-01 09:42:28.108 UTC [451] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE11132026-10-01 09:42:28.108 UTC [451] STATEMENT: -- name: CommitPendingClosure :exec1114 SELECT commit_pending_closure($1::bigint)1115 1116--- PASS: TestService_cleanupPendingClosuresHandler (0.36s)1117=== CONT TestGetExistingObjectsLocksRows11182026/10/01 09:42:28 OK 20241026095416_initial_model.sql (11.21ms)11192026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)11202026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.9ms)11212026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)11222026/10/01 09:42:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11232026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.93ms)11242026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.84ms)11252026/10/01 09:42:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2M5NmU4YjEtNDkwNy00ZWU4LWIzNWQtYzU0MzAyZTY4NjgzLjY4OWViMjlkLWE2YzEtNDU4YS1iMTgzLTI4ZDZhMWE2MDY4ZHgxNzkwODQ3NzQ4MTExOTU4Mzk51126--- PASS: TestReadRedirectKeepsNarinfoProxied (0.38s)1127=== CONT TestReadProxyDisabled11282026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.4ms)11292026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000011302026/10/01 09:42:28 OK 1_commit_pending_closure.sql (176.63ms)11312026/10/01 09:42:28 OK 2_object_stats_trigger.sql (12.23ms)11322026/10/01 09:42:28 OK 3_commit_push.sql (679.25µs)11332026/10/01 09:42:28 goose: up to current file version: 311342026/10/01 09:42:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2M5NmU4YjEtNDkwNy00ZWU4LWIzNWQtYzU0MzAyZTY4NjgzLjY4OWViMjlkLWE2YzEtNDU4YS1iMTgzLTI4ZDZhMWE2MDY4ZHgxNzkwODQ3NzQ4MTExOTU4Mzk5 parts=11135--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.58s)1136=== CONT TestClientFallsBackToClosures11372026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures11382026-10-01 09:42:28.337 UTC [489] ERROR: relation "goose_db_version" does not exist at character 3611392026-10-01 09:42:28.337 UTC [489] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11402026-10-01 09:42:28.337 UTC [490] ERROR: relation "goose_db_version" does not exist at character 3611412026-10-01 09:42:28.337 UTC [490] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1142--- PASS: TestService_Rustfstest (0.60s)1143=== CONT TestRegisterCompletedObjectNeedsPendingRow11442026/10/01 09:42:28 OK 20241026095416_initial_model.sql (12.39ms)11452026/10/01 09:42:28 OK 20241026095416_initial_model.sql (12.44ms)11462026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)11472026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)11482026/10/01 09:42:28 OK 20251218171726_add_pins.sql (5.04ms)11492026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.49ms)11502026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)11512026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)11522026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.07ms)11532026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.07ms)11542026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.59ms)11552026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.49ms)11562026/10/01 09:42:28 INFO Received push request method=POST path=/api/pushes11572026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.51ms)11582026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000011592026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (8.28ms)11602026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000011612026/10/01 09:42:28 OK 1_commit_pending_closure.sql (7.47ms)11622026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.18ms)11632026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.96ms)11642026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.59ms)11652026/10/01 09:42:28 OK 3_commit_push.sql (1.94ms)11662026/10/01 09:42:28 goose: up to current file version: 311672026/10/01 09:42:28 OK 3_commit_push.sql (2.62ms)11682026/10/01 09:42:28 goose: up to current file version: 311692026-10-01 09:42:28.396 UTC [494] ERROR: relation "goose_db_version" does not exist at character 3611702026-10-01 09:42:28.396 UTC [494] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11712026/10/01 09:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete11722026/10/01 09:42:28 INFO Received push request method=POST path=/api/pushes11732026-10-01 09:42:28.403 UTC [496] ERROR: relation "goose_db_version" does not exist at character 3611742026-10-01 09:42:28.403 UTC [496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/10/01 09:42:28 INFO Received push request method=POST path=/api/pushes11762026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.71ms)11772026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)1178--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.65s)1179=== CONT TestReadProxyRootRedirectsToIndexHTML11802026/10/01 09:42:28 OK 20251218171726_add_pins.sql (2.8ms)11812026/10/01 09:42:28 INFO Received push request method=POST path=/api/pushes11822026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.24ms)11832026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)11842026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)11852026/10/01 09:42:28 OK 20251218171726_add_pins.sql (2.59ms)11862026/10/01 09:42:28 OK 20260905000000_add_claims.sql (2.81ms)11872026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)11882026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.6ms)11892026-10-01 09:42:28.427 UTC [500] ERROR: relation "goose_db_version" does not exist at character 3611902026-10-01 09:42:28.427 UTC [500] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11912026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.01ms)11922026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000011932026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.33ms)11942026/10/01 09:42:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11952026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.83ms)11962026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.03ms)11972026/10/01 09:42:28 INFO Signed narinfos id=1 count=11198--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.66s)1199=== CONT TestClientPushesUseOnePush12002026/10/01 09:42:28 OK 2_object_stats_trigger.sql (2.44ms)12012026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.18ms)12022026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000012032026/10/01 09:42:28 OK 3_commit_push.sql (1.34ms)12042026/10/01 09:42:28 goose: up to current file version: 312052026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.13ms)12062026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.32ms)12072026/10/01 09:42:28 OK 3_commit_push.sql (1.31ms)12082026/10/01 09:42:28 goose: up to current file version: 312092026/10/01 09:42:28 INFO lead: acquired remote=192.0.2.1:123412102026/10/01 09:42:28 INFO lead: released remote=192.0.2.1:12341211--- PASS: TestLeadEndsOnShutdown (0.62s)1212=== CONT TestSweepSkipsRowsLockedByPush12132026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.52ms)12142026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)12152026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.49ms)12162026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)12172026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.93ms)12182026/10/01 09:42:28 INFO Received push request method=POST path=/api/pushes12192026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.85ms)12202026/10/01 09:42:28 INFO Aborted multipart uploads count=0 kept=012212026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.59ms)12222026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000012232026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.87ms)12242026/10/01 09:42:28 WARN Force mode enabled - objects will be deleted immediately without grace period12252026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.65ms)12262026/10/01 09:42:28 OK 3_commit_push.sql (1.41ms)12272026/10/01 09:42:28 goose: up to current file version: 312282026/10/01 09:42:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=012292026/10/01 09:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete12302026/10/01 09:42:28 INFO Vacuumed table table=pending_closures12312026-10-01 09:42:28.490 UTC [508] ERROR: relation "goose_db_version" does not exist at character 3612322026-10-01 09:42:28.490 UTC [508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12332026/10/01 09:42:28 INFO Vacuumed table table=pending_objects12342026/10/01 09:42:28 INFO Vacuumed table table=multipart_uploads1235--- PASS: TestPush_CompleteCommitsEveryRoot (0.67s)1236=== CONT TestReadProxyConditionalGet12372026/10/01 09:42:28 INFO Vacuumed table table=closures12382026/10/01 09:42:28 INFO Vacuumed table table=objects12392026/10/01 09:42:28 INFO Received complete push request method=POST path=/api/pushes/2/complete1240--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.73s)1241=== CONT TestPinProtectsFromGC12422026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.12ms)12432026-10-01 09:42:28.507 UTC [511] ERROR: relation "goose_db_version" does not exist at character 3612442026-10-01 09:42:28.507 UTC [511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12452026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)1246--- PASS: TestGCEndsOnShutdown (0.68s)1247=== CONT TestFailedS3DeleteKeepsTombstone12482026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.31ms)12492026-10-01 09:42:28.514 UTC [514] ERROR: relation "goose_db_version" does not exist at character 3612502026-10-01 09:42:28.514 UTC [514] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12512026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)12522026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.1ms)12532026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.42ms)12542026/10/01 09:42:28 INFO Aborted multipart uploads count=0 kept=012552026/10/01 09:42:28 INFO lead: acquired remote=192.0.2.1:123412562026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.72ms)12572026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.98ms)12582026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000012592026/10/01 09:42:28 WARN Force mode enabled - objects will be deleted immediately without grace period12602026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)12612026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.35ms)12622026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.64ms)12632026/10/01 09:42:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012642026/10/01 09:42:28 OK 3_commit_push.sql (1.39ms)12652026/10/01 09:42:28 goose: up to current file version: 312662026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.39ms)12672026/10/01 09:42:28 OK 20241026095416_initial_model.sql (11.36ms)12682026/10/01 09:42:28 INFO Vacuumed table table=pending_closures12692026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)12702026/10/01 09:42:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12712026/10/01 09:42:28 INFO Vacuumed table table=pending_objects12722026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)12732026/10/01 09:42:28 INFO Vacuumed table table=multipart_uploads12742026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.64ms)12752026/10/01 09:42:28 INFO Vacuumed table table=closures12762026/10/01 09:42:28 INFO Vacuumed table table=objects12772026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.05ms)12782026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.4ms)12792026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)12802026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (1.79ms)12812026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000012822026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.27ms)12832026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.34ms)1284--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.72s)1285=== CONT TestReadProxyHead12862026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.67ms)12872026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.53ms)12882026/10/01 09:42:28 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=M2M5NmU4YjEtNDkwNy00ZWU4LWIzNWQtYzU0MzAyZTY4NjgzLmVlMGNjZDZjLTQ0ZTMtNGViNy1iNGIzLWU2ZDUxY2IwZjI4ZngxNzkwODQ3NzQ4MDU1NjkwODA3 parts=1012892026/10/01 09:42:28 OK 3_commit_push.sql (1.86ms)12902026/10/01 09:42:28 goose: up to current file version: 312912026/10/01 09:42:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12922026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.32ms)12932026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000012942026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.2ms)12952026/10/01 09:42:28 INFO Completed upload id=112962026/10/01 09:42:28 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012972026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.45ms)12982026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures12992026/10/01 09:42:28 OK 3_commit_push.sql (1.21ms)13002026/10/01 09:42:28 goose: up to current file version: 31301--- PASS: TestReadProxyRangeRequest (0.79s)1302=== CONT TestClientSharedPathCommittedMidPush13032026/10/01 09:42:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures13042026/10/01 09:42:28 INFO Aborted multipart uploads count=0 kept=01305=== RUN TestPush_RejectsBadRequests/no_roots1306=== PAUSE TestPush_RejectsBadRequests/no_roots1307=== RUN TestPush_RejectsBadRequests/no_objects1308=== PAUSE TestPush_RejectsBadRequests/no_objects1309=== RUN TestPush_RejectsBadRequests/bad_root1310=== PAUSE TestPush_RejectsBadRequests/bad_root1311=== RUN TestPush_RejectsBadRequests/root_not_in_objects1312=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1313=== CONT TestForceGCDuringPushOffersSweptObject1314=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1315=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1316=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1317=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1318=== CONT TestClientWithDependencies13192026-10-01 09:42:28.571 UTC [543] ERROR: relation "goose_db_version" does not exist at character 3613202026-10-01 09:42:28.571 UTC [543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13212026/10/01 09:42:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013222026/10/01 09:42:28 INFO Vacuumed table table=pending_closures13232026/10/01 09:42:28 INFO Vacuumed table table=pending_objects13242026-10-01 09:42:28.591 UTC [546] ERROR: relation "goose_db_version" does not exist at character 3613252026-10-01 09:42:28.591 UTC [546] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13262026-10-01 09:42:28.591 UTC [547] ERROR: relation "goose_db_version" does not exist at character 3613272026-10-01 09:42:28.591 UTC [547] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13282026/10/01 09:42:28 OK 20241026095416_initial_model.sql (12.85ms)13292026/10/01 09:42:28 INFO Vacuumed table table=multipart_uploads13302026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)13312026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures13322026/10/01 09:42:28 INFO Vacuumed table table=closures13332026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.19ms)13342026/10/01 09:42:28 INFO Vacuumed table table=objects13352026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)13362026/10/01 09:42:28 OK 20260905000000_add_claims.sql (4.17ms)13372026/10/01 09:42:28 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013382026/10/01 09:42:28 OK 20241026095416_initial_model.sql (11.56ms)1339--- PASS: TestService_createPendingClosureHandler (0.86s)1340=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13412026/10/01 09:42:28 OK 20241026095416_initial_model.sql (13.58ms)13422026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (3.71ms)13432026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (5.16ms)13442026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)13452026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.53ms)13462026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000013472026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4ms)13482026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.15ms)13492026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.9ms)13502026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.77ms)13512026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)13522026/10/01 09:42:28 OK 3_commit_push.sql (1.27ms)13532026/10/01 09:42:28 goose: up to current file version: 313542026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)13552026/10/01 09:42:28 OK 20260905000000_add_claims.sql (4.61ms)13562026/10/01 09:42:28 OK 20260905000000_add_claims.sql (4.32ms)1357--- PASS: TestReadRedirectUsesPublicS3URL (0.80s)1358=== CONT TestClientMultipleUploads13592026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.13ms)13602026-10-01 09:42:28.638 UTC [552] ERROR: relation "goose_db_version" does not exist at character 3613612026-10-01 09:42:28.638 UTC [552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13622026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (9.7ms)13632026-10-01 09:42:28.638 UTC [553] ERROR: relation "goose_db_version" does not exist at character 3613642026-10-01 09:42:28.638 UTC [553] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13652026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (8.65ms)13662026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000013672026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.43ms)13682026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000013692026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.4ms)13702026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.44ms)13712026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.76ms)13722026/10/01 09:42:28 OK 3_commit_push.sql (1.34ms)13732026/10/01 09:42:28 goose: up to current file version: 313742026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.36ms)13752026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures13762026/10/01 09:42:28 OK 3_commit_push.sql (1.02ms)13772026/10/01 09:42:28 goose: up to current file version: 313782026-10-01 09:42:28.656 UTC [555] ERROR: relation "goose_db_version" does not exist at character 3613792026-10-01 09:42:28.656 UTC [555] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13802026/10/01 09:42:28 OK 20241026095416_initial_model.sql (13.45ms)13812026/10/01 09:42:28 OK 20241026095416_initial_model.sql (13.65ms)13822026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)13832026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)13842026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.44ms)13852026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.49ms)13862026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures13872026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)13882026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)13892026/10/01 09:42:28 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13902026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures13912026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.5ms)13922026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.67ms)1393--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.85s)1394=== CONT TestGCSweepDeliversEachKeyOnce13952026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.51ms)13962026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.16ms)13972026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.09ms)13982026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)13992026/10/01 09:42:28 INFO lead: released remote=192.0.2.1:123414002026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.2ms)14012026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000014022026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.03ms)14032026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000014042026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.44ms)14052026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.75ms)14062026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.23ms)14072026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures14082026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.22ms)14092026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.79ms)14102026/10/01 09:42:28 OK 3_commit_push.sql (1.01ms)14112026/10/01 09:42:28 goose: up to current file version: 314122026/10/01 09:42:28 OK 3_commit_push.sql (1.04ms)14132026/10/01 09:42:28 goose: up to current file version: 314142026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)14152026/10/01 09:42:28 OK 20260905000000_add_claims.sql (2.72ms)14162026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (1.89ms)14172026-10-01 09:42:28.690 UTC [558] ERROR: relation "goose_db_version" does not exist at character 3614182026-10-01 09:42:28.690 UTC [558] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14192026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.62ms)14202026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000014212026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.31ms)14222026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.09ms)14232026/10/01 09:42:28 OK 3_commit_push.sql (1.01ms)14242026/10/01 09:42:28 goose: up to current file version: 314252026/10/01 09:42:28 INFO Aborted multipart uploads count=0 kept=014262026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.39ms)14272026-10-01 09:42:28.708 UTC [560] ERROR: relation "goose_db_version" does not exist at character 3614282026-10-01 09:42:28.708 UTC [560] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14292026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)14302026/10/01 09:42:28 WARN Force mode enabled - objects will be deleted immediately without grace period14312026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.21ms)14322026/10/01 09:42:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14332026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)14342026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.38ms)14352026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.4ms)14362026/10/01 09:42:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014372026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.08ms)14382026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000014392026/10/01 09:42:28 INFO lead: acquired remote=192.0.2.1:123414402026/10/01 09:42:28 OK 20241026095416_initial_model.sql (10.64ms)14412026/10/01 09:42:28 INFO Vacuumed table table=pending_closures14422026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.44ms)14432026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)14442026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.34ms)14452026/10/01 09:42:28 INFO Vacuumed table table=pending_objects14462026/10/01 09:42:28 INFO Vacuumed table table=multipart_uploads14472026/10/01 09:42:28 OK 3_commit_push.sql (1.35ms)14482026/10/01 09:42:28 goose: up to current file version: 314492026/10/01 09:42:28 INFO Vacuumed table table=closures14502026/10/01 09:42:28 INFO lead: released remote=192.0.2.1:12341451--- PASS: TestLeadElectsOneAndHandsOver (0.90s)1452=== CONT TestTombstonedObjectOfferedWithoutWaiting14532026/10/01 09:42:28 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=M2M5NmU4YjEtNDkwNy00ZWU4LWIzNWQtYzU0MzAyZTY4NjgzLjc3MWRlZDY0LTc1OGUtNDBhMC1hNzYzLTc1ZGE5MjRhYTAyNHgxNzkwODQ3NzQ4MzQxMzY3MTA2 parts=1214542026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.58ms)14552026/10/01 09:42:28 INFO Vacuumed table table=objects14562026/10/01 09:42:28 INFO Received uploads request method=POST path=/api/pending_closures1457--- PASS: TestSweepRechecksPendingAfterLocking (0.82s)1458=== CONT TestClientIntegration14592026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)1460--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.98s)1461=== CONT TestGCSweepSkipsPendingObjects1462--- PASS: TestReadRedirectNar (0.66s)1463=== CONT TestReadProxyInvalidPath14642026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.31ms)14652026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.24ms)14662026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.17ms)14672026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000014682026-10-01 09:42:28.743 UTC [569] ERROR: relation "goose_db_version" does not exist at character 3614692026-10-01 09:42:28.743 UTC [569] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14702026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.08ms)14712026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.5ms)14722026/10/01 09:42:28 OK 3_commit_push.sql (1.91ms)14732026/10/01 09:42:28 goose: up to current file version: 31474--- PASS: TestGetExistingObjectsLocksRows (0.66s)1475=== CONT TestClientErrorHandling1476=== RUN TestClientErrorHandling/InvalidStorePath1477=== PAUSE TestClientErrorHandling/InvalidStorePath1478=== RUN TestClientErrorHandling/InvalidAuthToken1479=== PAUSE TestClientErrorHandling/InvalidAuthToken1480=== RUN TestClientErrorHandling/ServerNotAvailable1481=== PAUSE TestClientErrorHandling/ServerNotAvailable1482=== CONT TestCompleteMultipartUnregistered14832026/10/01 09:42:28 OK 20241026095416_initial_model.sql (18.91ms)14842026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)1485--- PASS: TestReadProxyDisabled (0.64s)1486=== CONT TestClientCADerivations14872026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.48ms)14882026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)14892026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.93ms)14902026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.03ms)14912026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.77ms)14922026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000014932026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.88ms)14942026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.96ms)14952026/10/01 09:42:28 OK 3_commit_push.sql (1.69ms)14962026/10/01 09:42:28 goose: up to current file version: 314972026-10-01 09:42:28.811 UTC [578] ERROR: relation "goose_db_version" does not exist at character 3614982026-10-01 09:42:28.811 UTC [578] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1499--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.46s)1500=== CONT TestCacheStatsHandler15012026-10-01 09:42:28.821 UTC [579] ERROR: relation "goose_db_version" does not exist at character 3615022026-10-01 09:42:28.821 UTC [579] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15032026-10-01 09:42:28.823 UTC [581] ERROR: relation "goose_db_version" does not exist at character 3615042026-10-01 09:42:28.823 UTC [581] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15052026-10-01 09:42:28.823 UTC [580] ERROR: relation "goose_db_version" does not exist at character 3615062026-10-01 09:42:28.823 UTC [580] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15072026/10/01 09:42:28 OK 20241026095416_initial_model.sql (12.55ms)15082026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)15092026/10/01 09:42:28 OK 20251218171726_add_pins.sql (4.15ms)15102026/10/01 09:42:28 OK 20241026095416_initial_model.sql (11.06ms)1511--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.42s)1512=== CONT TestDeduplicatedObjectsRecordedAsPending15132026/10/01 09:42:28 OK 20241026095416_initial_model.sql (12.38ms)15142026/10/01 09:42:28 OK 20241026095416_initial_model.sql (11.75ms)15152026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)15162026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)15172026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)15182026-10-01 09:42:28.844 UTC [601] ERROR: relation "goose_db_version" does not exist at character 3615192026-10-01 09:42:28.844 UTC [601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15202026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)15212026/10/01 09:42:28 OK 20251218171726_add_pins.sql (5.24ms)15222026/10/01 09:42:28 OK 20251218171726_add_pins.sql (5.56ms)15232026/10/01 09:42:28 OK 20251218171726_add_pins.sql (5.38ms)15242026/10/01 09:42:28 OK 20260905000000_add_claims.sql (5.78ms)15252026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)15262026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.58ms)15272026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)15282026-10-01 09:42:28.854 UTC [604] ERROR: relation "goose_db_version" does not exist at character 3615292026-10-01 09:42:28.854 UTC [604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15302026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)15312026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.35ms)15322026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000015332026/10/01 09:42:28 OK 20260905000000_add_claims.sql (3.61ms)15342026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.66ms)15352026/10/01 09:42:28 OK 20260905000000_add_claims.sql (4.37ms)15362026/10/01 09:42:28 OK 20260905000000_add_claims.sql (4.17ms)15372026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.98ms)15382026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.57ms)15392026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (2.98ms)15402026/10/01 09:42:28 OK 3_commit_push.sql (1.63ms)15412026/10/01 09:42:28 goose: up to current file version: 315422026/10/01 09:42:28 OK 20260920000000_drop_claims.sql (3.2ms)15432026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.61ms)15442026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000015452026/10/01 09:42:28 OK 20241026095416_initial_model.sql (11.5ms)15462026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (2.06ms)15472026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000015482026/10/01 09:42:28 OK 20260923120000_add_pushes.sql (1.9ms)15492026/10/01 09:42:28 goose: successfully migrated database to version: 2026092312000015502026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.25ms)15512026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)15522026/10/01 09:42:28 OK 1_commit_pending_closure.sql (1.83ms)15532026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.25ms)15542026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.26ms)15552026/10/01 09:42:28 OK 1_commit_pending_closure.sql (2.44ms)15562026/10/01 09:42:28 OK 3_commit_push.sql (1.3ms)15572026/10/01 09:42:28 goose: up to current file version: 315582026/10/01 09:42:28 OK 3_commit_push.sql (1.32ms)15592026/10/01 09:42:28 goose: up to current file version: 315602026/10/01 09:42:28 OK 20251218171726_add_pins.sql (3.65ms)15612026/10/01 09:42:28 OK 2_object_stats_trigger.sql (1.96ms)15622026/10/01 09:42:28 OK 3_commit_push.sql (1.52ms)15632026/10/01 09:42:28 goose: up to current file version: 315642026/10/01 09:42:28 OK 20241026095416_initial_model.sql (9.72ms)15652026/10/01 09:42:28 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)15662026/10/01 09:42:28 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)15672026/10/01 09:42:29 OK 20260905000000_add_claims.sql (156.73ms)15682026/10/01 09:42:29 OK 20251218171726_add_pins.sql (173.77ms)15692026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (19.89ms)15702026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (5.38ms)15712026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (3.85ms)15722026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000015732026/10/01 09:42:29 OK 1_commit_pending_closure.sql (1.94ms)15742026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.85ms)15752026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.6ms)15762026/10/01 09:42:29 OK 3_commit_push.sql (894.41µs)15772026/10/01 09:42:29 goose: up to current file version: 315782026-10-01 09:42:29.058 UTC [660] ERROR: relation "goose_db_version" does not exist at character 3615792026-10-01 09:42:29.058 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15802026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.87ms)15812026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=015822026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.32ms)15832026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000015842026-10-01 09:42:29.063 UTC [663] ERROR: relation "goose_db_version" does not exist at character 3615852026-10-01 09:42:29.063 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15862026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.07ms)15872026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period15882026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.33ms)15892026/10/01 09:42:29 OK 3_commit_push.sql (1.08ms)15902026/10/01 09:42:29 goose: up to current file version: 315912026/10/01 09:42:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015922026/10/01 09:42:29 INFO Vacuumed table table=pending_closures15932026/10/01 09:42:29 INFO Vacuumed table table=pending_objects15942026/10/01 09:42:29 INFO Vacuumed table table=multipart_uploads15952026/10/01 09:42:29 INFO Vacuumed table table=closures1596--- PASS: TestReadProxyConditionalGet (0.58s)1597=== CONT TestService_AuthMiddleware_OIDC15982026/10/01 09:42:29 INFO Vacuumed table table=objects15992026/10/01 09:42:29 OK 20241026095416_initial_model.sql (10.61ms)16002026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)16012026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=016022026/10/01 09:42:29 OK 20251218171726_add_pins.sql (2.98ms)16032026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period16042026/10/01 09:42:29 OK 20241026095416_initial_model.sql (10.47ms)16052026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (2.88ms)16062026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)16072026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures16082026/10/01 09:42:29 OK 20260905000000_add_claims.sql (2.86ms)16092026/10/01 09:42:29 OK 20251218171726_add_pins.sql (2.89ms)16102026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (1.83ms)16112026/10/01 09:42:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=016122026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (2.85ms)16132026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (1.46ms)16142026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000016152026/10/01 09:42:29 INFO Vacuumed table table=pending_closures16162026/10/01 09:42:29 INFO Vacuumed table table=pending_objects16172026/10/01 09:42:29 INFO Vacuumed table table=multipart_uploads16182026/10/01 09:42:29 INFO Vacuumed table table=closures16192026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.08ms)16202026/10/01 09:42:29 OK 20260905000000_add_claims.sql (2.6ms)16212026/10/01 09:42:29 INFO Vacuumed table table=objects16222026/10/01 09:42:29 OK 2_object_stats_trigger.sql (818.99µs)16232026/10/01 09:42:29 OK 3_commit_push.sql (639.87µs)16242026/10/01 09:42:29 goose: up to current file version: 316252026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (1.94ms)1626--- PASS: TestSweepSkipsRowsLockedByPush (0.65s)1627=== CONT TestService_ReadAuthMiddleware16282026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.04ms)16292026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000016302026/10/01 09:42:29 OK 1_commit_pending_closure.sql (1.46ms)1631--- PASS: TestPushWaitsForSweepHoldingRow (1.27s)1632=== CONT TestCacheConfigHandler1633=== RUN TestCacheConfigHandler/full_config,_no_issuer1634=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1635=== RUN TestCacheConfigHandler/no_cache_url_configured1636=== PAUSE TestCacheConfigHandler/no_cache_url_configured1637=== RUN TestCacheConfigHandler/no_signing_keys1638=== PAUSE TestCacheConfigHandler/no_signing_keys16392026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.05ms)1640=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1641=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1642=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16432026/10/01 09:42:29 OK 3_commit_push.sql (874.09µs)16442026/10/01 09:42:29 goose: up to current file version: 316452026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures16462026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures16472026/10/01 09:42:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16482026/10/01 09:42:29 INFO Uploading 19vj2vn9cn1lh8y2agai3x057zkhfav3-shared-dep (136B)16492026/10/01 09:42:29 INFO Uploading g9qi64l32haki3sq7xvfb07cx250cv1j-b (216B)16502026/10/01 09:42:29 WARN Failed to register uploaded object key=6n50yb4mbk4xxw2pd8jlwjy8i939isf5.ls error="server returned 404: 404 page not found\n"16512026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16522026/10/01 09:42:29 WARN Failed to register uploaded object key=g9qi64l32haki3sq7xvfb07cx250cv1j.ls error="server returned 404: 404 page not found\n"16532026/10/01 09:42:29 WARN Failed to register uploaded object key=19vj2vn9cn1lh8y2agai3x057zkhfav3.ls error="server returned 404: 404 page not found\n"16542026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16552026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/1i29m7v7p42n3dagxxjmxll64p3qkjglmx9zpwbgp5754vhazj4m.nar.zst error="server returned 404: 404 page not found\n"16562026/10/01 09:42:29 INFO Signed narinfos id=1 count=216572026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16582026/10/01 09:42:29 INFO Signed narinfos id=2 count=216592026/10/01 09:42:29 INFO Uploading 4 narinfos16602026/10/01 09:42:29 WARN Failed to register uploaded object key=6n50yb4mbk4xxw2pd8jlwjy8i939isf5.narinfo error="server returned 404: 404 page not found\n"16612026/10/01 09:42:29 WARN Failed to register uploaded object key=g9qi64l32haki3sq7xvfb07cx250cv1j.narinfo error="server returned 404: 404 page not found\n"16622026/10/01 09:42:29 WARN Failed to register uploaded object key=19vj2vn9cn1lh8y2agai3x057zkhfav3.narinfo error="server returned 404: 404 page not found\n"16632026/10/01 09:42:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16642026/10/01 09:42:29 WARN Failed to register uploaded object key=19vj2vn9cn1lh8y2agai3x057zkhfav3.narinfo error="server returned 404: 404 page not found\n"16652026/10/01 09:42:29 INFO Completed upload id=116662026/10/01 09:42:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1667--- PASS: TestReadProxyHead (0.60s)1668=== CONT TestPushDedupSurvivesConcurrentGC16692026/10/01 09:42:29 INFO Completed upload id=216702026/10/01 09:42:29 INFO Upload complete. (73ms)1671=== NAME TestClientFallsBackToClosures1672 client_pushes_test.go:112: Retrieved narinfo from S3:1673 StorePath: /build/TestClientFallsBackToClosures2276373723/001/store/19vj2vn9cn1lh8y2agai3x057zkhfav3-shared-dep1674 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1675 Compression: zstd1676 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821677 NarSize: 1361678 References: 1679 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1680 client_pushes_test.go:112: Retrieved narinfo from S3:1681 StorePath: /build/TestClientFallsBackToClosures2276373723/001/store/6n50yb4mbk4xxw2pd8jlwjy8i939isf5-a1682 URL: nar/1i29m7v7p42n3dagxxjmxll64p3qkjglmx9zpwbgp5754vhazj4m.nar.zst1683 Compression: zstd1684 NarHash: sha256:1i29m7v7p42n3dagxxjmxll64p3qkjglmx9zpwbgp5754vhazj4m1685 NarSize: 2161686 References: /build/TestClientFallsBackToClosures2276373723/001/store/19vj2vn9cn1lh8y2agai3x057zkhfav3-shared-dep1687 CA: text:sha256:1i8vk4115f9b5y42d1m49s17p4rnnj7iimx4jnw1b6l09g3xci2g16882026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=01689 client_pushes_test.go:112: Retrieved narinfo from S3:1690 StorePath: /build/TestClientFallsBackToClosures2276373723/001/store/g9qi64l32haki3sq7xvfb07cx250cv1j-b1691 URL: nar/1i29m7v7p42n3dagxxjmxll64p3qkjglmx9zpwbgp5754vhazj4m.nar.zst1692 Compression: zstd1693 NarHash: sha256:1i29m7v7p42n3dagxxjmxll64p3qkjglmx9zpwbgp5754vhazj4m1694 NarSize: 2161695 References: /build/TestClientFallsBackToClosures2276373723/001/store/19vj2vn9cn1lh8y2agai3x057zkhfav3-shared-dep1696 CA: text:sha256:1i8vk4115f9b5y42d1m49s17p4rnnj7iimx4jnw1b6l09g3xci2g16972026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period1698--- PASS: TestClientFallsBackToClosures (0.83s)1699=== CONT TestService_ReadScope_PublicByDefault17002026-10-01 09:42:29.167 UTC [794] ERROR: relation "goose_db_version" does not exist at character 3617012026-10-01 09:42:29.167 UTC [794] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17022026/10/01 09:42:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17032026/10/01 09:42:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."17042026-10-01 09:42:29.175 UTC [798] ERROR: relation "goose_db_version" does not exist at character 3617052026-10-01 09:42:29.175 UTC [798] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1706--- PASS: TestFailedS3DeleteKeepsTombstone (0.67s)1707=== CONT TestService_AuthMiddleware_MTLSProxyHeader1708=== NAME TestPinProtectsFromGC1709 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1664030140/001/store/plsimj6rycqihalps4518fvwfzpikcww-pinned-file.txt1710 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1664030140/001/store/gdhwsy1i9vcn6yy354x7wgna55lv8xgq-unpinned-file.txt17112026/10/01 09:42:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17122026/10/01 09:42:29 OK 20241026095416_initial_model.sql (18.22ms)17132026/10/01 09:42:29 OK 20241026095416_initial_model.sql (11.67ms)17142026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures17152026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)17162026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes17172026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)17182026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.99ms)17192026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.97ms)17202026/10/01 09:42:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17212026/10/01 09:42:29 INFO Uploading 97s2jif9s0l21viqpkfb7vwgzf32r15n-shared-dep (136B)17222026/10/01 09:42:29 INFO Uploading ndw1p35v4y9wpw0w1vywzsg4fr6lf9id-a (216B)17232026/10/01 09:42:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38239/oidc17242026/10/01 09:42:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=M2M5NmU4YjEtNDkwNy00ZWU4LWIzNWQtYzU0MzAyZTY4NjgzLjM2M2NkYmFiLWY0NDktNGY1ZC1hZmYyLWI4NzZjNTlhYmNkZngxNzkwODQ3NzQ4Njc1MjI0MTYz parts=1217252026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)17262026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)17272026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures17282026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/1hsimszw2d4vs8mqmv6hs0rj6dw18qszx0v7kcbhfph25p53f4c6.nar.zst error="server returned 404: 404 page not found\n"17292026/10/01 09:42:29 WARN Failed to register uploaded object key=ndw1p35v4y9wpw0w1vywzsg4fr6lf9id.ls error="server returned 404: 404 page not found\n"17302026/10/01 09:42:29 WARN Failed to register uploaded object key=jzm93jivpznhcxdh165rynrk8f555lfv.ls error="server returned 404: 404 page not found\n"17312026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17322026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17332026/10/01 09:42:29 WARN Failed to register uploaded object key=97s2jif9s0l21viqpkfb7vwgzf32r15n.ls error="server returned 404: 404 page not found\n"17342026/10/01 09:42:29 INFO Signed narinfos id=1 count=317352026/10/01 09:42:29 INFO Uploading 3 narinfos17362026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.98ms)17372026/10/01 09:42:29 OK 20260905000000_add_claims.sql (4.18ms)17382026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (3.36ms)17392026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.78ms)17402026/10/01 09:42:29 WARN Failed to register uploaded object key=ndw1p35v4y9wpw0w1vywzsg4fr6lf9id.narinfo error="server returned 404: 404 page not found\n"17412026/10/01 09:42:29 WARN Failed to register uploaded object key=jzm93jivpznhcxdh165rynrk8f555lfv.narinfo error="server returned 404: 404 page not found\n"17422026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures17432026/10/01 09:42:29 INFO Received complete push request method=POST path=/api/pushes/1/complete17442026/10/01 09:42:29 WARN Failed to register uploaded object key=97s2jif9s0l21viqpkfb7vwgzf32r15n.narinfo error="server returned 404: 404 page not found\n"17452026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.8ms)17462026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000017472026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (4.12ms)17482026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000017492026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.58ms)17502026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.6ms)17512026/10/01 09:42:29 INFO Upload complete. (64ms)17522026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.68ms)1753=== NAME TestClientPushesUseOnePush17542026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.06ms)1755 client_pushes_test.go:97: Retrieved narinfo from S3:1756 StorePath: /build/TestClientPushesUseOnePush4150151349/001/store/97s2jif9s0l21viqpkfb7vwgzf32r15n-shared-dep1757 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1758 Compression: zstd1759 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821760 NarSize: 1361761 References: 1762 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17632026/10/01 09:42:29 OK 3_commit_push.sql (1.59ms)17642026/10/01 09:42:29 goose: up to current file version: 317652026/10/01 09:42:29 OK 3_commit_push.sql (1.64ms)17662026/10/01 09:42:29 goose: up to current file version: 31767 client_pushes_test.go:97: Retrieved narinfo from S3:1768 StorePath: /build/TestClientPushesUseOnePush4150151349/001/store/ndw1p35v4y9wpw0w1vywzsg4fr6lf9id-a1769 URL: nar/1hsimszw2d4vs8mqmv6hs0rj6dw18qszx0v7kcbhfph25p53f4c6.nar.zst1770 Compression: zstd1771 NarHash: sha256:1hsimszw2d4vs8mqmv6hs0rj6dw18qszx0v7kcbhfph25p53f4c61772 NarSize: 2161773 References: /build/TestClientPushesUseOnePush4150151349/001/store/97s2jif9s0l21viqpkfb7vwgzf32r15n-shared-dep1774 CA: text:sha256:151bhqca91576fssr2iawpfz5lwham0arsqcnpx3q9j3b6kip6xp1775 client_pushes_test.go:97: Retrieved narinfo from S3:1776 StorePath: /build/TestClientPushesUseOnePush4150151349/001/store/jzm93jivpznhcxdh165rynrk8f555lfv-b1777 URL: nar/1hsimszw2d4vs8mqmv6hs0rj6dw18qszx0v7kcbhfph25p53f4c6.nar.zst1778 Compression: zstd1779 NarHash: sha256:1hsimszw2d4vs8mqmv6hs0rj6dw18qszx0v7kcbhfph25p53f4c61780 NarSize: 2161781 References: /build/TestClientPushesUseOnePush4150151349/001/store/97s2jif9s0l21viqpkfb7vwgzf32r15n-shared-dep1782 CA: text:sha256:151bhqca91576fssr2iawpfz5lwham0arsqcnpx3q9j3b6kip6xp1783--- PASS: TestClientPushesUseOnePush (0.80s)1784=== CONT TestGCMetrics17852026-10-01 09:42:29.232 UTC [892] ERROR: relation "goose_db_version" does not exist at character 3617862026-10-01 09:42:29.232 UTC [892] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17872026-10-01 09:42:29.248 UTC [946] ERROR: relation "goose_db_version" does not exist at character 3617882026-10-01 09:42:29.248 UTC [946] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1789=== NAME TestClientMultipleUploads1790 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1806996088/001/store/bbzbfnqyngxxqcjq5canb65cal520np2-test-file-0.txt1791=== NAME TestClientWithDependencies1792 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2497424690/001/store/msw11aqbfckz05y7n6rb3c63pcaqn758-test-script17932026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes17942026/10/01 09:42:29 OK 20241026095416_initial_model.sql (12.79ms)17952026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)17962026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures17972026/10/01 09:42:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17982026/10/01 09:42:29 INFO Uploading plsimj6rycqihalps4518fvwfzpikcww-pinned-file.txt (128B)17992026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=018002026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18012026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18022026/10/01 09:42:29 WARN Failed to register uploaded object key=plsimj6rycqihalps4518fvwfzpikcww.ls error="server returned 404: 404 page not found\n"18032026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period18042026/10/01 09:42:29 INFO Signed narinfos id=1 count=118052026/10/01 09:42:29 INFO Uploading 1 narinfos18062026/10/01 09:42:29 OK 20251218171726_add_pins.sql (9.86ms)18072026/10/01 09:42:29 OK 20241026095416_initial_model.sql (11.14ms)18082026/10/01 09:42:29 INFO Received complete push request method=POST path=/api/pushes/1/complete18092026/10/01 09:42:29 WARN Failed to register uploaded object key=plsimj6rycqihalps4518fvwfzpikcww.narinfo error="server returned 404: 404 page not found\n"18102026-10-01 09:42:29.267 UTC [967] ERROR: relation "goose_db_version" does not exist at character 3618112026-10-01 09:42:29.267 UTC [967] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18122026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)18132026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)1814--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.54s)1815=== CONT TestReadProxy40418162026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.34ms)18172026/10/01 09:42:29 OK 20251218171726_add_pins.sql (4.28ms)18182026/10/01 09:42:29 INFO Upload complete. (59ms)1819--- PASS: TestReadProxyInvalidPath (0.54s)1820=== CONT TestGCBugBareHashReferences18212026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes18222026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.97ms)18232026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)18242026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.64ms)18252026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000018262026/10/01 09:42:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=018272026/10/01 09:42:29 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18282026/10/01 09:42:29 INFO Uploading jviyr2afw4p16mqzs1n4j2g2rc9vi0nr-top (224B)18292026/10/01 09:42:29 INFO Uploading lgdjhlkp22iyhfj9whvbsywycja6ircf-shared-dep (136B)18302026/10/01 09:42:29 INFO Vacuumed table table=pending_closures1831=== NAME TestClientMultipleUploads1832 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1806996088/001/store/nnv18lap28z29g9af69bfbmizpnny7cx-test-file-1.txt18332026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.36ms)18342026/10/01 09:42:29 INFO Vacuumed table table=pending_objects18352026-10-01 09:42:29.281 UTC [1006] ERROR: relation "goose_db_version" does not exist at character 3618362026-10-01 09:42:29.281 UTC [1006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18372026/10/01 09:42:29 INFO Vacuumed table table=multipart_uploads18382026/10/01 09:42:29 OK 20260905000000_add_claims.sql (4.18ms)18392026/10/01 09:42:29 INFO Vacuumed table table=closures18402026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.67ms)18412026/10/01 09:42:29 OK 3_commit_push.sql (1.47ms)18422026/10/01 09:42:29 goose: up to current file version: 318432026/10/01 09:42:29 OK 20241026095416_initial_model.sql (10.1ms)18442026/10/01 09:42:29 WARN Failed to register uploaded object key=jviyr2afw4p16mqzs1n4j2g2rc9vi0nr.ls error="server returned 404: 404 page not found\n"18452026/10/01 09:42:29 INFO Vacuumed table table=objects18462026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (3.18ms)18472026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18482026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18492026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/1i5slmhn507p94gwai9jli5aa7wlm5cnklrnhmk9ry2aczdcp9c6.nar.zst error="server returned 404: 404 page not found\n"18502026/10/01 09:42:29 WARN Failed to register uploaded object key=lgdjhlkp22iyhfj9whvbsywycja6ircf.ls error="server returned 404: 404 page not found\n"1851=== NAME TestClientWithDependencies1852 client_integration_test.go:615: Found 1 dependencies (including self)1853--- PASS: TestGCSweepDeliversEachKeyOnce (0.61s)1854=== CONT TestMultipartCleanup18552026/10/01 09:42:29 INFO Signed narinfos id=1 count=218562026/10/01 09:42:29 INFO Uploading 2 narinfos18572026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)18582026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.66ms)18592026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000018602026/10/01 09:42:29 INFO Received complete push request method=POST path=/api/pushes/1/complete18612026/10/01 09:42:29 WARN Failed to register uploaded object key=jviyr2afw4p16mqzs1n4j2g2rc9vi0nr.narinfo error="server returned 404: 404 page not found\n"18622026/10/01 09:42:29 WARN Failed to register uploaded object key=lgdjhlkp22iyhfj9whvbsywycja6ircf.narinfo error="server returned 404: 404 page not found\n"18632026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.68ms)18642026/10/01 09:42:29 OK 20251218171726_add_pins.sql (4.33ms)18652026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.54ms)18662026/10/01 09:42:29 OK 3_commit_push.sql (1.37ms)18672026/10/01 09:42:29 goose: up to current file version: 318682026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)18692026/10/01 09:42:29 INFO Upload complete. (61ms)1870=== NAME TestClientSharedPathCommittedMidPush1871 client_integration_test.go:680: Retrieved narinfo from S3:1872 StorePath: /build/TestClientSharedPathCommittedMidPush1537742204/001/store/lgdjhlkp22iyhfj9whvbsywycja6ircf-shared-dep1873 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1874 Compression: zstd1875 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821876 NarSize: 1361877 References: 1878 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18792026/10/01 09:42:29 OK 20241026095416_initial_model.sql (13.51ms)18802026/10/01 09:42:29 OK 20260905000000_add_claims.sql (4.99ms)1881 client_integration_test.go:680: Retrieved narinfo from S3:1882 StorePath: /build/TestClientSharedPathCommittedMidPush1537742204/001/store/jviyr2afw4p16mqzs1n4j2g2rc9vi0nr-top1883 URL: nar/1i5slmhn507p94gwai9jli5aa7wlm5cnklrnhmk9ry2aczdcp9c6.nar.zst1884 Compression: zstd1885 NarHash: sha256:1i5slmhn507p94gwai9jli5aa7wlm5cnklrnhmk9ry2aczdcp9c61886 NarSize: 2241887 References: /build/TestClientSharedPathCommittedMidPush1537742204/001/store/lgdjhlkp22iyhfj9whvbsywycja6ircf-shared-dep1888 CA: text:sha256:18cqaazq3wkpkx74ny5cqgaswqa6dklar8qy5xnm6fl76a6xz6ly18892026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)18902026-10-01 09:42:29.302 UTC [1028] ERROR: relation "goose_db_version" does not exist at character 3618912026-10-01 09:42:29.302 UTC [1028] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18922026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.69ms)1893--- PASS: TestClientSharedPathCommittedMidPush (0.75s)1894=== CONT TestService_verifyS3Integrity18952026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (3.21ms)18962026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000018972026/10/01 09:42:29 OK 20251218171726_add_pins.sql (5.53ms)18982026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.5ms)18992026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.3ms)19002026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)19012026/10/01 09:42:29 OK 3_commit_push.sql (1.9ms)19022026/10/01 09:42:29 goose: up to current file version: 31903--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.28s)1904=== CONT TestService_RequireScope_OIDC19052026/10/01 09:42:29 OK 20260905000000_add_claims.sql (4.15ms)1906=== NAME TestClientMultipleUploads1907 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1806996088/001/store/2bl33irsa42401jgkgs7aacvl03cgi48-test-file-2.txt19082026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.9ms)19092026/10/01 09:42:29 OK 20241026095416_initial_model.sql (12.3ms)19102026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures19112026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (3.1ms)19122026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000019132026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)19142026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.64ms)19152026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.73ms)19162026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.93ms)19172026/10/01 09:42:29 OK 3_commit_push.sql (1.23ms)19182026/10/01 09:42:29 goose: up to current file version: 319192026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)1920=== NAME TestClientIntegration1921 client_integration_test.go:286: Created store path: /build/TestClientIntegration1419242598/002/store/v88cv6mzdh2p7wxg0bv6r0h9x9fv0q38-test-file.txt19222026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes19232026/10/01 09:42:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19242026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=019252026/10/01 09:42:29 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1926--- PASS: TestCompleteMultipartUnregistered (0.58s)1927=== CONT TestGenerateLandingPage19282026/10/01 09:42:29 OK 20260905000000_add_claims.sql (10.58ms)19292026/10/01 09:42:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19302026/10/01 09:42:29 INFO Uploading gdhwsy1i9vcn6yy354x7wgna55lv8xgq-unpinned-file.txt (128B)1931--- PASS: TestGenerateLandingPage (0.00s)1932=== CONT TestService_healthCheckHandler19332026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.65ms)19342026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period19352026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.17ms)19362026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000019372026/10/01 09:42:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019382026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19392026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19402026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.49ms)19412026/10/01 09:42:29 WARN Failed to register uploaded object key=gdhwsy1i9vcn6yy354x7wgna55lv8xgq.ls error="server returned 404: 404 page not found\n"19422026/10/01 09:42:29 INFO Signed narinfos id=2 count=119432026/10/01 09:42:29 INFO Uploading 1 narinfos19442026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.8ms)19452026/10/01 09:42:29 INFO Vacuumed table table=pending_closures19462026/10/01 09:42:29 OK 3_commit_push.sql (1.35ms)19472026/10/01 09:42:29 goose: up to current file version: 319482026/10/01 09:42:29 INFO Vacuumed table table=pending_objects19492026-10-01 09:42:29.354 UTC [1123] ERROR: relation "goose_db_version" does not exist at character 3619502026-10-01 09:42:29.354 UTC [1123] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19512026/10/01 09:42:29 INFO Vacuumed table table=multipart_uploads19522026/10/01 09:42:29 INFO Received complete push request method=POST path=/api/pushes/2/complete19532026-10-01 09:42:29.354 UTC [1122] ERROR: relation "goose_db_version" does not exist at character 3619542026-10-01 09:42:29.354 UTC [1122] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19552026/10/01 09:42:29 WARN Failed to register uploaded object key=gdhwsy1i9vcn6yy354x7wgna55lv8xgq.narinfo error="server returned 404: 404 page not found\n"19562026/10/01 09:42:29 INFO Vacuumed table table=closures19572026/10/01 09:42:29 INFO Vacuumed table table=objects19582026/10/01 09:42:29 INFO Upload complete. (53ms)19592026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes19602026/10/01 09:42:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19612026/10/01 09:42:29 INFO Uploading msw11aqbfckz05y7n6rb3c63pcaqn758-test-script (136B)1962--- PASS: TestGCSweepSkipsPendingObjects (0.63s)1963=== CONT TestGracefulShutdownDrainsInflight19642026/10/01 09:42:29 INFO Starting HTTP server address=127.0.0.1:3300519652026/10/01 09:42:29 INFO Shutdown signal received, draining in-flight requests timeout=10s19662026-10-01 09:42:29.369 UTC [1160] ERROR: relation "goose_db_version" does not exist at character 3619672026-10-01 09:42:29.369 UTC [1160] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19682026/10/01 09:42:29 WARN Failed to register uploaded object key=log/0idwhkqk0r64kra2szbi8jyz5nxhw36n-test-script.drv error="server returned 404: 404 page not found\n"19692026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19702026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19712026/10/01 09:42:29 WARN Failed to register uploaded object key=msw11aqbfckz05y7n6rb3c63pcaqn758.ls error="server returned 404: 404 page not found\n"19722026/10/01 09:42:29 INFO Signed narinfos id=1 count=119732026/10/01 09:42:29 INFO Uploading 1 narinfos19742026/10/01 09:42:29 OK 20241026095416_initial_model.sql (11.21ms)19752026/10/01 09:42:29 OK 20241026095416_initial_model.sql (12.64ms)19762026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)19772026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)19782026/10/01 09:42:29 INFO Received complete push request method=POST path=/api/pushes/1/complete19792026/10/01 09:42:29 WARN Failed to register uploaded object key=msw11aqbfckz05y7n6rb3c63pcaqn758.narinfo error="server returned 404: 404 page not found\n"19802026/10/01 09:42:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46395/oidc19812026/10/01 09:42:29 OK 20251218171726_add_pins.sql (4.02ms)19822026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.83ms)19832026/10/01 09:42:29 INFO Upload complete. (63ms)19842026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)19852026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)1986=== NAME TestClientWithDependencies1987 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2497424690/001/store) requires matching store prefix19882026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.51ms)19892026/10/01 09:42:29 OK 20241026095416_initial_model.sql (10.78ms)19902026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.75ms)19912026-10-01 09:42:29.387 UTC [1181] ERROR: relation "goose_db_version" does not exist at character 3619922026-10-01 09:42:29.387 UTC [1181] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19932026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)1994--- PASS: TestClientWithDependencies (0.82s)1995=== CONT TestMetricsInventory19962026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.74ms)19972026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (3.65ms)19982026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.68ms)19992026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes20002026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (3.17ms)20012026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000020022026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.73ms)20032026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000020042026/10/01 09:42:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures20052026/10/01 09:42:29 INFO Garbage collection started20062026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.36ms)20072026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.66ms)20082026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.85ms)2009--- PASS: TestCacheStatsHandler (0.58s)2010=== CONT TestService_readinessHandler20112026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.79ms)20122026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.56ms)20132026/10/01 09:42:29 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20142026/10/01 09:42:29 INFO Uploading bbzbfnqyngxxqcjq5canb65cal520np2-test-file-0.txt (160B)20152026/10/01 09:42:29 INFO Uploading 2bl33irsa42401jgkgs7aacvl03cgi48-test-file-2.txt (160B)20162026/10/01 09:42:29 INFO Uploading nnv18lap28z29g9af69bfbmizpnny7cx-test-file-1.txt (160B)20172026/10/01 09:42:29 OK 3_commit_push.sql (1.32ms)20182026/10/01 09:42:29 goose: up to current file version: 320192026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.76ms)20202026/10/01 09:42:29 OK 3_commit_push.sql (1.98ms)20212026/10/01 09:42:29 goose: up to current file version: 320222026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.61ms)20232026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20242026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20252026/10/01 09:42:29 WARN Failed to register uploaded object key=2bl33irsa42401jgkgs7aacvl03cgi48.ls error="server returned 404: 404 page not found\n"2026--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.79s)2027=== CONT TestGCTaskStore_Fail2028--- PASS: TestGCTaskStore_Fail (0.00s)2029=== CONT TestCacheConfigHandlerMaxNarSize20302026/10/01 09:42:29 WARN Failed to register uploaded object key=bbzbfnqyngxxqcjq5canb65cal520np2.ls error="server returned 404: 404 page not found\n"2031--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)2032=== CONT TestNARDeduplicationMetadataUploadBug20332026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20342026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20352026/10/01 09:42:29 WARN Failed to register uploaded object key=nnv18lap28z29g9af69bfbmizpnny7cx.ls error="server returned 404: 404 page not found\n"20362026/10/01 09:42:29 INFO Signed narinfos id=1 count=320372026/10/01 09:42:29 INFO Uploading 3 narinfos20382026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.77ms)20392026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000020402026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes20412026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=020422026/10/01 09:42:29 OK 20241026095416_initial_model.sql (11.73ms)20432026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.58ms)20442026/10/01 09:42:29 WARN Failed to register uploaded object key=bbzbfnqyngxxqcjq5canb65cal520np2.narinfo error="server returned 404: 404 page not found\n"20452026/10/01 09:42:29 INFO Received complete push request method=POST path=/api/pushes/1/complete20462026/10/01 09:42:29 WARN Failed to register uploaded object key=2bl33irsa42401jgkgs7aacvl03cgi48.narinfo error="server returned 404: 404 page not found\n"20472026/10/01 09:42:29 WARN Failed to register uploaded object key=nnv18lap28z29g9af69bfbmizpnny7cx.narinfo error="server returned 404: 404 page not found\n"20482026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (3.03ms)20492026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures20502026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period20512026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.39ms)20522026/10/01 09:42:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20532026/10/01 09:42:29 INFO Uploading v88cv6mzdh2p7wxg0bv6r0h9x9fv0q38-test-file.txt (152B)20542026/10/01 09:42:29 OK 3_commit_push.sql (1.65ms)20552026/10/01 09:42:29 goose: up to current file version: 320562026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.59ms)20572026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"20582026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20592026/10/01 09:42:29 INFO Upload complete. (61ms)2060=== NAME TestClientMultipleUploads20612026/10/01 09:42:29 WARN Failed to register uploaded object key=v88cv6mzdh2p7wxg0bv6r0h9x9fv0q38.ls error="server returned 404: 404 page not found\n"2062 client_integration_test.go:369: Uploaded 3 paths in 96.887902ms20632026/10/01 09:42:29 INFO Signed narinfos id=1 count=120642026/10/01 09:42:29 INFO Uploading 1 narinfos20652026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)2066--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.58s)2067=== CONT TestServerTLSConfig2068=== RUN TestServerTLSConfig/no_client_CA2069=== PAUSE TestServerTLSConfig/no_client_CA2070=== RUN TestServerTLSConfig/missing_CA_file2071=== PAUSE TestServerTLSConfig/missing_CA_file2072=== RUN TestServerTLSConfig/not_a_PEM_file2073=== PAUSE TestServerTLSConfig/not_a_PEM_file2074=== CONT TestCreatePendingClosureRejectsOversizedNAR20752026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures2076--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2077=== CONT TestParseSingleRange2078=== RUN TestParseSingleRange/none2079=== PAUSE TestParseSingleRange/none2080=== RUN TestParseSingleRange/unknown_unit2081=== PAUSE TestParseSingleRange/unknown_unit2082=== RUN TestParseSingleRange/multi-range_ignored2083=== PAUSE TestParseSingleRange/multi-range_ignored2084=== RUN TestParseSingleRange/malformed_no_dash2085=== PAUSE TestParseSingleRange/malformed_no_dash2086=== RUN TestParseSingleRange/malformed_both_empty2087=== PAUSE TestParseSingleRange/malformed_both_empty2088=== RUN TestParseSingleRange/malformed_end_before_start2089=== PAUSE TestParseSingleRange/malformed_end_before_start2090=== RUN TestParseSingleRange/closed2091=== PAUSE TestParseSingleRange/closed2092=== RUN TestParseSingleRange/open-ended2093=== PAUSE TestParseSingleRange/open-ended2094=== RUN TestParseSingleRange/end_clamped_to_size2095=== PAUSE TestParseSingleRange/end_clamped_to_size2096=== RUN TestParseSingleRange/suffix2097=== PAUSE TestParseSingleRange/suffix2098=== RUN TestParseSingleRange/suffix_exceeds_size2099=== PAUSE TestParseSingleRange/suffix_exceeds_size2100=== RUN TestParseSingleRange/single_byte2101=== PAUSE TestParseSingleRange/single_byte2102=== RUN TestParseSingleRange/start_past_EOF2103=== PAUSE TestParseSingleRange/start_past_EOF2104=== RUN TestParseSingleRange/start_far_past_EOF2105=== PAUSE TestParseSingleRange/start_far_past_EOF2106=== CONT TestService_NativeMTLS21072026/10/01 09:42:29 INFO Received complete push request method=POST path=/api/pushes/1/complete21082026/10/01 09:42:29 WARN Failed to register uploaded object key=v88cv6mzdh2p7wxg0bv6r0h9x9fv0q38.narinfo error="server returned 404: 404 page not found\n"2109--- PASS: TestClientMultipleUploads (0.79s)2110=== CONT TestReadProxyNarStreaming21112026/10/01 09:42:29 OK 20260905000000_add_claims.sql (9.18ms)2112--- PASS: TestService_ReadAuthMiddleware (0.33s)2113=== CONT TestUploadHandlersRejectInvalidKeys2114=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2115=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2116=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2117=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2118=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2119=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2120=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2121=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2122=== CONT TestCreatePin_ReservedPins21232026/10/01 09:42:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=021242026/10/01 09:42:29 INFO Upload complete. (58ms)21252026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (3.21ms)21262026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.77ms)21272026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000021282026/10/01 09:42:29 INFO Vacuumed table table=pending_closures21292026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.42ms)2130--- PASS: TestGracefulShutdownDrainsInflight (0.07s)2131=== CONT TestIsValidCachePath2132=== RUN TestIsValidCachePath/narinfo2133=== PAUSE TestIsValidCachePath/narinfo2134=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars2135=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars2136=== RUN TestIsValidCachePath/nar_zst2137=== PAUSE TestIsValidCachePath/nar_zst2138=== RUN TestIsValidCachePath/nar_xz2139=== PAUSE TestIsValidCachePath/nar_xz2140=== RUN TestIsValidCachePath/nar_bz22141=== PAUSE TestIsValidCachePath/nar_bz22142=== RUN TestIsValidCachePath/nar_uncompressed2143=== PAUSE TestIsValidCachePath/nar_uncompressed2144=== RUN TestIsValidCachePath/ls2145=== PAUSE TestIsValidCachePath/ls2146=== RUN TestIsValidCachePath/log2147=== PAUSE TestIsValidCachePath/log2148=== RUN TestIsValidCachePath/realisation2149=== PAUSE TestIsValidCachePath/realisation2150=== RUN TestIsValidCachePath/nix-cache-info2151=== PAUSE TestIsValidCachePath/nix-cache-info2152=== RUN TestIsValidCachePath/index.html2153=== PAUSE TestIsValidCachePath/index.html2154=== RUN TestIsValidCachePath/traversal_parent2155=== PAUSE TestIsValidCachePath/traversal_parent2156=== RUN TestIsValidCachePath/traversal_in_middle2157=== PAUSE TestIsValidCachePath/traversal_in_middle2158=== RUN TestIsValidCachePath/invalid_char_e2159=== PAUSE TestIsValidCachePath/invalid_char_e2160=== RUN TestIsValidCachePath/invalid_char_u2161=== PAUSE TestIsValidCachePath/invalid_char_u2162=== RUN TestIsValidCachePath/random_path2163=== PAUSE TestIsValidCachePath/random_path2164=== RUN TestIsValidCachePath/empty2165=== PAUSE TestIsValidCachePath/empty2166=== RUN TestIsValidCachePath/leading_slash21672026/10/01 09:42:29 INFO Vacuumed table table=pending_objects2168=== PAUSE TestIsValidCachePath/leading_slash2169=== RUN TestIsValidCachePath/wrong_extension2170=== PAUSE TestIsValidCachePath/wrong_extension2171=== RUN TestIsValidCachePath/short_hash2172=== PAUSE TestIsValidCachePath/short_hash2173=== CONT TestReadProxyNarinfo21742026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.33ms)21752026/10/01 09:42:29 INFO Vacuumed table table=multipart_uploads21762026/10/01 09:42:29 OK 3_commit_push.sql (1.61ms)21772026/10/01 09:42:29 goose: up to current file version: 321782026/10/01 09:42:29 INFO Vacuumed table table=closures21792026-10-01 09:42:29.440 UTC [1266] ERROR: relation "goose_db_version" does not exist at character 3621802026-10-01 09:42:29.440 UTC [1266] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21812026/10/01 09:42:29 INFO Vacuumed table table=objects21822026/10/01 09:42:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21832026/10/01 09:42:29 WARN mTLS auth: bound subjects configured but subject DN unavailable21842026/10/01 09:42:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2185--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.35s)2186=== CONT TestPresentNotReportedWhileGCDeletesClosure2187=== NAME TestClientCADerivations2188 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2762125487/001/store/74ywj7qwwjwcw37hsl24kg6q8wnm44hb-ca-test21892026-10-01 09:42:29.460 UTC [1289] ERROR: relation "goose_db_version" does not exist at character 3621902026-10-01 09:42:29.460 UTC [1289] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21912026/10/01 09:42:29 INFO All 1 paths already cached2192=== NAME TestClientIntegration2193 client_integration_test.go:312: Retrieved narinfo from S3:2194 StorePath: /build/TestClientIntegration1419242598/002/store/v88cv6mzdh2p7wxg0bv6r0h9x9fv0q38-test-file.txt2195 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2196 Compression: zstd2197 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12198 NarSize: 1522199 References: 2200 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12201 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2202 client_integration_test.go:313: Decompressed .ls content (64 bytes):2203 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2204 client_integration_test.go:316: Testing garbage collection...22052026/10/01 09:42:29 OK 20241026095416_initial_model.sql (21.8ms)22062026-10-01 09:42:29.471 UTC [1307] ERROR: relation "goose_db_version" does not exist at character 3622072026-10-01 09:42:29.471 UTC [1307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22082026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)22092026/10/01 09:42:29 OK 20251218171726_add_pins.sql (4.27ms)22102026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)22112026-10-01 09:42:29.483 UTC [1309] ERROR: relation "goose_db_version" does not exist at character 3622122026-10-01 09:42:29.483 UTC [1309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22132026/10/01 09:42:29 OK 20241026095416_initial_model.sql (13.51ms)22142026/10/01 09:42:29 OK 20260905000000_add_claims.sql (4.1ms)22152026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (2ms)22162026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.83ms)22172026/10/01 09:42:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40377/oidc22182026/10/01 09:42:29 OK 20251218171726_add_pins.sql (4.21ms)2219=== NAME TestClientCADerivations2220 client_ca_test.go:139: Found 1 dependencies (including self)22212026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (3.16ms)22222026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000022232026/10/01 09:42:29 OK 20241026095416_initial_model.sql (12.89ms)22242026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures2225--- PASS: TestService_ReadScope_PublicByDefault (0.33s)2226=== CONT TestProxyHeadersOnlyTrustedOnSocket22272026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)22282026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.47ms)22292026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)22302026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.23ms)22312026-10-01 09:42:29.497 UTC [1327] ERROR: relation "goose_db_version" does not exist at character 3622322026-10-01 09:42:29.497 UTC [1327] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22332026/10/01 09:42:29 OK 3_commit_push.sql (1.21ms)22342026/10/01 09:42:29 goose: up to current file version: 322352026/10/01 09:42:29 OK 20251218171726_add_pins.sql (4.06ms)22362026/10/01 09:42:29 OK 20241026095416_initial_model.sql (9.28ms)22372026/10/01 09:42:29 OK 20260905000000_add_claims.sql (4.25ms)22382026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)22392026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)22402026/10/01 09:42:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures22412026/10/01 09:42:29 INFO Garbage collection started22422026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (3.54ms)22432026/10/01 09:42:29 OK 20251218171726_add_pins.sql (2.84ms)22442026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.92ms)22452026-10-01 09:42:29.506 UTC [1349] ERROR: relation "goose_db_version" does not exist at character 3622462026-10-01 09:42:29.506 UTC [1349] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22472026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (3.23ms)22482026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000022492026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)22502026-10-01 09:42:29.509 UTC [1350] ERROR: relation "goose_db_version" does not exist at character 3622512026-10-01 09:42:29.509 UTC [1350] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22522026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.96ms)22532026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.41ms)22542026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=022552026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.11ms)22562026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.45ms)22572026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000022582026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.12ms)22592026-10-01 09:42:29.513 UTC [1352] ERROR: relation "goose_db_version" does not exist at character 3622602026-10-01 09:42:29.513 UTC [1352] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2261--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.34s)2262=== CONT TestReadProxyNarinfoAlreadyDecompressed22632026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (9.35ms)22642026/10/01 09:42:29 OK 3_commit_push.sql (8.8ms)22652026/10/01 09:42:29 goose: up to current file version: 322662026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period22672026/10/01 09:42:29 OK 20241026095416_initial_model.sql (17.47ms)22682026/10/01 09:42:29 OK 1_commit_pending_closure.sql (9.07ms)22692026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (3.03ms)22702026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (5.15ms)22712026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000022722026/10/01 09:42:29 OK 20241026095416_initial_model.sql (12.3ms)22732026/10/01 09:42:29 OK 2_object_stats_trigger.sql (4.39ms)22742026/10/01 09:42:29 OK 3_commit_push.sql (2.89ms)22752026/10/01 09:42:29 goose: up to current file version: 322762026/10/01 09:42:29 OK 1_commit_pending_closure.sql (6.67ms)22772026/10/01 09:42:29 OK 20251218171726_add_pins.sql (8.33ms)22782026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (7ms)22792026/10/01 09:42:29 OK 20241026095416_initial_model.sql (13.33ms)22802026/10/01 09:42:29 OK 2_object_stats_trigger.sql (3.94ms)22812026/10/01 09:42:29 OK 20241026095416_initial_model.sql (14.68ms)22822026/10/01 09:42:29 OK 20251218171726_add_pins.sql (5.87ms)22832026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (5.95ms)22842026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (3.81ms)22852026/10/01 09:42:29 OK 3_commit_push.sql (4.22ms)22862026/10/01 09:42:29 goose: up to current file version: 322872026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (4.42ms)22882026-10-01 09:42:29.543 UTC [1372] ERROR: relation "goose_db_version" does not exist at character 3622892026-10-01 09:42:29.543 UTC [1372] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22902026/10/01 09:42:29 OK 20251218171726_add_pins.sql (5.69ms)22912026/10/01 09:42:29 OK 20251218171726_add_pins.sql (5.52ms)22922026/10/01 09:42:29 OK 20260905000000_add_claims.sql (8.05ms)22932026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (8.15ms)22942026/10/01 09:42:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=022952026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (6.67ms)22962026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (5.32ms)22972026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (5.6ms)22982026/10/01 09:42:29 OK 20260905000000_add_claims.sql (5.52ms)22992026/10/01 09:42:29 INFO Vacuumed table table=pending_closures23002026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (3.95ms)23012026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (5.21ms)23022026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000023032026/10/01 09:42:29 OK 20260905000000_add_claims.sql (5.09ms)23042026/10/01 09:42:29 OK 20260905000000_add_claims.sql (6.08ms)23052026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=023062026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (20.8ms)23072026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000023082026/10/01 09:42:29 OK 1_commit_pending_closure.sql (19.79ms)23092026/10/01 09:42:29 OK 20241026095416_initial_model.sql (26.57ms)2310=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2311=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2312=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2313=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2314=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2315=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected23162026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (21.11ms)2317=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured23182026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (21.19ms)2319=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2320=== CONT TestOrphanedObjectsGCStressTest23212026/10/01 09:42:29 INFO Vacuumed table table=pending_objects23222026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.24ms)23232026/10/01 09:42:29 INFO Vacuumed table table=multipart_uploads23242026/10/01 09:42:29 OK 1_commit_pending_closure.sql (3.05ms)23252026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)23262026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.31ms)23272026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000023282026/10/01 09:42:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023292026/10/01 09:42:29 OK 3_commit_push.sql (2.01ms)23302026/10/01 09:42:29 goose: up to current file version: 323312026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.72ms)23322026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (3.51ms)23332026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000023342026/10/01 09:42:29 INFO Vacuumed table table=closures23352026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.02ms)23362026/10/01 09:42:29 OK 3_commit_push.sql (1.55ms)23372026/10/01 09:42:29 goose: up to current file version: 323382026/10/01 09:42:29 INFO Vacuumed table table=pending_closures23392026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.46ms)23402026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.87ms)23412026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.43ms)23422026/10/01 09:42:29 INFO Vacuumed table table=objects23432026/10/01 09:42:29 OK 3_commit_push.sql (1.33ms)23442026/10/01 09:42:29 goose: up to current file version: 323452026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.94ms)23462026/10/01 09:42:29 INFO Vacuumed table table=pending_objects23472026/10/01 09:42:29 INFO Vacuumed table table=multipart_uploads23482026/10/01 09:42:29 OK 3_commit_push.sql (1.23ms)23492026/10/01 09:42:29 goose: up to current file version: 323502026-10-01 09:42:29.589 UTC [1394] ERROR: relation "goose_db_version" does not exist at character 3623512026-10-01 09:42:29.589 UTC [1394] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23522026-10-01 09:42:29.589 UTC [1395] ERROR: relation "goose_db_version" does not exist at character 3623532026-10-01 09:42:29.589 UTC [1395] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23542026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)23552026/10/01 09:42:29 INFO Vacuumed table table=closures23562026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.2ms)23572026/10/01 09:42:29 INFO Vacuumed table table=objects23582026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.01ms)23592026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (1.56ms)23602026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000023612026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=023622026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.2ms)23632026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period23642026/10/01 09:42:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023652026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.57ms)23662026/10/01 09:42:29 OK 3_commit_push.sql (705.83µs)23672026/10/01 09:42:29 goose: up to current file version: 323682026/10/01 09:42:29 INFO Vacuumed table table=pending_closures23692026/10/01 09:42:29 INFO Vacuumed table table=pending_objects23702026/10/01 09:42:29 INFO Vacuumed table table=multipart_uploads23712026/10/01 09:42:29 OK 20241026095416_initial_model.sql (11.37ms)23722026-10-01 09:42:29.607 UTC [1397] ERROR: relation "goose_db_version" does not exist at character 3623732026-10-01 09:42:29.607 UTC [1397] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23742026/10/01 09:42:29 OK 20241026095416_initial_model.sql (12.07ms)23752026/10/01 09:42:29 INFO Vacuumed table table=closures23762026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)23772026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)23782026/10/01 09:42:29 INFO Vacuumed table table=objects2379--- PASS: TestPushDedupSurvivesConcurrentGC (0.46s)2380=== CONT TestOrphanedObjectsGC23812026/10/01 09:42:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23822026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.11ms)23832026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.78ms)23842026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=023852026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes23862026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)23872026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)23882026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period23892026/10/01 09:42:29 OK 20260905000000_add_claims.sql (2.83ms)23902026/10/01 09:42:29 OK 20260905000000_add_claims.sql (2.93ms)23912026/10/01 09:42:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23922026/10/01 09:42:29 INFO Uploading 74ywj7qwwjwcw37hsl24kg6q8wnm44hb-ca-test (144B)23932026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (1.81ms)23942026/10/01 09:42:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023952026/10/01 09:42:29 INFO Vacuumed table table=pending_closures23962026/10/01 09:42:29 INFO Vacuumed table table=pending_objects23972026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (3.24ms)23982026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (1.95ms)23992026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000024002026/10/01 09:42:29 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2M5NmU4YjEtNDkwNy00ZWU4LWIzNWQtYzU0MzAyZTY4NjgzLjkxYzQ2NDNiLTY3ZGMtNDY5NC1iNzIzLTRmMjZhMmQzNDU5YXgxNzkwODQ3NzQ5MjE0MTM0MDI2 error="Get \"http://127.0.0.1:1/bucket25/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"24012026/10/01 09:42:29 INFO Vacuumed table table=multipart_uploads24022026/10/01 09:42:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2M5NmU4YjEtNDkwNy00ZWU4LWIzNWQtYzU0MzAyZTY4NjgzLjc4YjUyZTZhLTRjYTgtNGI1My05ZmMyLTZlZjg4OTkzMzZhZngxNzkwODQ3NzQ5MjA3NTQ1MDA2 parts=1224032026/10/01 09:42:29 INFO Vacuumed table table=closures24042026/10/01 09:42:29 INFO Vacuumed table table=objects24052026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.17ms)24062026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000024072026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"24082026/10/01 09:42:29 INFO Received cleanup request method=DELETE path=/api/pending_closures24092026/10/01 09:42:29 WARN Failed to register uploaded object key=log/xqzgz6q094a3i90586d9giri62vb7zid-ca-test.drv error="server returned 404: 404 page not found\n"24102026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24112026/10/01 09:42:29 WARN Failed to register uploaded object key=74ywj7qwwjwcw37hsl24kg6q8wnm44hb.ls error="server returned 404: 404 page not found\n"2412--- PASS: TestReadProxy404 (0.36s)2413=== CONT TestPresentReportsOnlyClosureRoots24142026/10/01 09:42:29 INFO Signed narinfos id=1 count=124152026/10/01 09:42:29 INFO Uploading 1 narinfos2416--- PASS: TestGCMetrics (0.40s)2417=== CONT TestIsValidUploadKey2418=== RUN TestIsValidUploadKey/narinfo2419=== PAUSE TestIsValidUploadKey/narinfo2420=== RUN TestIsValidUploadKey/nar_zst2421=== PAUSE TestIsValidUploadKey/nar_zst2422=== RUN TestIsValidUploadKey/nar_xz2423=== PAUSE TestIsValidUploadKey/nar_xz2424=== RUN TestIsValidUploadKey/nar_plain2425=== PAUSE TestIsValidUploadKey/nar_plain2426=== RUN TestIsValidUploadKey/listing2427=== PAUSE TestIsValidUploadKey/listing2428=== RUN TestIsValidUploadKey/build_log2429=== PAUSE TestIsValidUploadKey/build_log2430=== RUN TestIsValidUploadKey/build_log_home-manager_file2431=== PAUSE TestIsValidUploadKey/build_log_home-manager_file2432=== RUN TestIsValidUploadKey/build_log_plus_in_name2433=== PAUSE TestIsValidUploadKey/build_log_plus_in_name2434=== RUN TestIsValidUploadKey/build_log_question_mark2435=== PAUSE TestIsValidUploadKey/build_log_question_mark2436=== RUN TestIsValidUploadKey/build_log_equals2437=== PAUSE TestIsValidUploadKey/build_log_equals2438=== RUN TestIsValidUploadKey/realisation2439=== PAUSE TestIsValidUploadKey/realisation2440=== RUN TestIsValidUploadKey/realisation_plus_in_output24412026/10/01 09:42:29 INFO Aborted multipart uploads count=1 kept=02442=== PAUSE TestIsValidUploadKey/realisation_plus_in_output2443=== RUN TestIsValidUploadKey/nix-cache-info2444=== PAUSE TestIsValidUploadKey/nix-cache-info2445=== RUN TestIsValidUploadKey/index.html2446=== PAUSE TestIsValidUploadKey/index.html2447=== RUN TestIsValidUploadKey/narinfo_key,_nar_type2448=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type2449=== RUN TestIsValidUploadKey/nar_key,_narinfo_type2450=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type2451=== RUN TestIsValidUploadKey/listing_key,_narinfo_type2452=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type2453=== RUN TestIsValidUploadKey/traversal2454=== PAUSE TestIsValidUploadKey/traversal2455=== RUN TestIsValidUploadKey/traversal_nar2456=== PAUSE TestIsValidUploadKey/traversal_nar2457=== RUN TestIsValidUploadKey/absolute2458=== PAUSE TestIsValidUploadKey/absolute2459=== RUN TestIsValidUploadKey/empty_key2460=== PAUSE TestIsValidUploadKey/empty_key2461=== RUN TestIsValidUploadKey/unknown_type2462=== PAUSE TestIsValidUploadKey/unknown_type2463=== CONT TestObjectStatsTrigger24642026/10/01 09:42:29 INFO Received complete push request method=POST path=/api/pushes/1/complete24652026/10/01 09:42:29 WARN Failed to register uploaded object key=74ywj7qwwjwcw37hsl24kg6q8wnm44hb.narinfo error="server returned 404: 404 page not found\n"24662026/10/01 09:42:29 OK 1_commit_pending_closure.sql (8.21ms)24672026/10/01 09:42:29 OK 1_commit_pending_closure.sql (7.75ms)24682026/10/01 09:42:29 OK 20241026095416_initial_model.sql (18.72ms)24692026/10/01 09:42:29 OK 2_object_stats_trigger.sql (2.36ms)24702026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.71ms)2471--- PASS: TestRedundantMultipartUpload (1.81s)2472=== CONT TestProxyWriteTimeout/narinfo24732026/10/01 09:42:29 OK 3_commit_push.sql (1.53ms)2474=== CONT TestProxyWriteTimeout/10_GiB_nar24752026/10/01 09:42:29 goose: up to current file version: 32476=== CONT TestProxyWriteTimeout/unknown_size2477=== CONT TestProxyWriteTimeout/1_GiB_nar2478--- PASS: TestProxyWriteTimeout (0.08s)2479 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2480 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2481 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2482 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2483=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure24842026/10/01 09:42:29 INFO Received uploads request method=POST path=/24852026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)24862026/10/01 09:42:29 OK 3_commit_push.sql (1.26ms)24872026/10/01 09:42:29 goose: up to current file version: 324882026/10/01 09:42:29 INFO Upload complete. (111ms)24892026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.75ms)2490=== NAME TestClientCADerivations2491 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2762125487/001/store/74ywj7qwwjwcw37hsl24kg6q8wnm44hb-ca-test2492 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2493 Compression: zstd2494 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2495 NarSize: 1442496 References: 2497 Deriver: /build/TestClientCADerivations2762125487/001/store/xqzgz6q094a3i90586d9giri62vb7zid-ca-test.drv2498 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2499 client_ca_test.go:185: Checking for realisation files in S3...2500 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2501 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache25022026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)25032026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.71ms)25042026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (3.64ms)25052026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.85ms)25062026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000025072026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.68ms)25082026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.71ms)25092026-10-01 09:42:29.658 UTC [1423] ERROR: relation "goose_db_version" does not exist at character 3625102026-10-01 09:42:29.658 UTC [1423] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25112026/10/01 09:42:29 OK 3_commit_push.sql (1.41ms)25122026/10/01 09:42:29 goose: up to current file version: 325132026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures25142026/10/01 09:42:29 OK 20241026095416_initial_model.sql (10.11ms)25152026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)25162026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.21ms)25172026-10-01 09:42:29.680 UTC [1442] ERROR: relation "goose_db_version" does not exist at character 3625182026-10-01 09:42:29.680 UTC [1442] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25192026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures25202026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)25212026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.03ms)25222026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (2.45ms)25232026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.45ms)25242026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000025252026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.24ms)25262026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.16ms)25272026/10/01 09:42:29 OK 3_commit_push.sql (912.89µs)25282026/10/01 09:42:29 goose: up to current file version: 325292026/10/01 09:42:29 OK 20241026095416_initial_model.sql (10.01ms)25302026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)2531--- PASS: TestService_healthCheckHandler (0.36s)2532=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts25332026/10/01 09:42:29 INFO Received request for more parts method=POST path=/25342026/10/01 09:42:29 OK 20251218171726_add_pins.sql (2.75ms)25352026-10-01 09:42:29.703 UTC [1443] ERROR: relation "goose_db_version" does not exist at character 3625362026-10-01 09:42:29.703 UTC [1443] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25372026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)25382026/10/01 09:42:29 OK 20260905000000_add_claims.sql (2.81ms)25392026-10-01 09:42:29.706 UTC [1444] ERROR: relation "goose_db_version" does not exist at character 3625402026-10-01 09:42:29.706 UTC [1444] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25412026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (1.79ms)25422026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (1.9ms)25432026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000025442026/10/01 09:42:29 OK 1_commit_pending_closure.sql (1.55ms)25452026/10/01 09:42:29 OK 2_object_stats_trigger.sql (688.83µs)25462026/10/01 09:42:29 OK 3_commit_push.sql (558.11µs)25472026/10/01 09:42:29 goose: up to current file version: 325482026/10/01 09:42:29 OK 20241026095416_initial_model.sql (9.76ms)25492026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)25502026/10/01 09:42:29 OK 20241026095416_initial_model.sql (9.14ms)25512026/10/01 09:42:29 OK 20251218171726_add_pins.sql (2.58ms)25522026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)25532026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.16ms)25542026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.39ms)25552026/10/01 09:42:29 OK 20260905000000_add_claims.sql (2.66ms)25562026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3ms)2557=== NAME TestClientCADerivations2558 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2559 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2560 error: binary cache 's3://bucket50?endpoint=http://localhost:36775®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2762125487/001/store'2561 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 125622026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (1.71ms)25632026/10/01 09:42:29 OK 20260905000000_add_claims.sql (2.33ms)25642026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (1.5ms)25652026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000025662026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (1.67ms)2567--- PASS: TestClientCADerivations (0.96s)2568=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart25692026/10/01 09:42:29 INFO Received complete multipart upload request method=POST path=/25702026/10/01 09:42:29 OK 1_commit_pending_closure.sql (1.56ms)25712026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (1.44ms)25722026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000025732026/10/01 09:42:29 OK 2_object_stats_trigger.sql (784.35µs)25742026/10/01 09:42:29 OK 3_commit_push.sql (545.43µs)25752026/10/01 09:42:29 goose: up to current file version: 325762026/10/01 09:42:29 OK 1_commit_pending_closure.sql (1.54ms)25772026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.14ms)2578=== RUN TestService_RequireScope_OIDC/builder_may_write2579=== PAUSE TestService_RequireScope_OIDC/builder_may_write2580=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2581=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2582=== RUN TestService_RequireScope_OIDC/ops_may_admin2583=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2584=== RUN TestService_RequireScope_OIDC/ops_may_not_write2585=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2586=== RUN TestService_RequireScope_OIDC/reader_may_not_write2587=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2588=== RUN TestService_RequireScope_OIDC/static_token_may_admin2589=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2590=== RUN TestService_RequireScope_OIDC/static_token_may_write2591=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2592=== RUN TestService_RequireScope_OIDC/reader_may_read2593=== PAUSE TestService_RequireScope_OIDC/reader_may_read2594=== RUN TestService_RequireScope_OIDC/writer_implies_read2595=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2596=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2597=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2598=== CONT TestResolveDBConnectionString/flag_wins2599=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2600=== CONT TestResolveDBConnectionString/nothing_configured2601=== CONT TestResolveDBConnectionString/file_when_flag_empty2602=== CONT TestResolveDBConnectionString/missing_file_is_an_error26032026/10/01 09:42:29 OK 3_commit_push.sql (764.11µs)26042026/10/01 09:42:29 goose: up to current file version: 32605=== CONT TestPush_RejectsBadRequests/no_roots26062026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes2607=== CONT TestPush_RejectsBadRequests/bad_root26082026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes2609=== CONT TestPush_RejectsBadRequests/no_objects26102026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes2611=== CONT TestPush_RejectsBadRequests/root_not_in_objects26122026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes2613--- PASS: TestResolveDBConnectionString (0.00s)2614 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2615 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2616 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2617 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2618 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2619--- PASS: TestPush_RejectsBadRequests (0.74s)2620 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2621 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2622 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2623 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2624=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2625--- PASS: TestMetricsInventory (0.36s)2626=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check26272026/10/01 09:42:29 WARN readiness check failed error="closed pool"2628--- PASS: TestService_readinessHandler (0.36s)2629=== CONT TestClientErrorHandling/InvalidStorePath2630=== CONT TestClientErrorHandling/ServerNotAvailable26312026/10/01 09:42:29 INFO Received cleanup request method=DELETE path=/api/pending_closures26322026/10/01 09:42:29 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket62/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""26332026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=126342026/10/01 09:42:29 INFO Received cleanup request method=DELETE path=/api/pending_closures26352026/10/01 09:42:29 INFO Aborted multipart uploads count=1 kept=02636--- PASS: TestMultipartCleanup (0.51s)2637=== CONT TestClientErrorHandling/InvalidAuthToken26382026/10/01 09:42:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"26392026/10/01 09:42:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2640--- PASS: TestService_NativeMTLS (0.37s)2641=== CONT TestCacheConfigHandler/full_config,_no_issuer2642=== CONT TestCacheConfigHandler/no_signing_keys2643=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2644=== CONT TestCacheConfigHandler/no_cache_url_configured2645--- PASS: TestCacheConfigHandler (0.00s)2646 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2647 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2648 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2649 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2650=== CONT TestServerTLSConfig/no_client_CA2651=== CONT TestServerTLSConfig/missing_CA_file2652=== CONT TestServerTLSConfig/not_a_PEM_file2653--- PASS: TestServerTLSConfig (0.00s)2654 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2655 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2656 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2657=== CONT TestParseSingleRange/none2658=== CONT TestParseSingleRange/start_past_EOF2659=== CONT TestParseSingleRange/single_byte2660=== CONT TestParseSingleRange/suffix_exceeds_size2661=== CONT TestParseSingleRange/suffix2662=== CONT TestParseSingleRange/end_clamped_to_size2663=== CONT TestParseSingleRange/open-ended2664=== CONT TestParseSingleRange/closed2665=== CONT TestParseSingleRange/start_far_past_EOF2666=== CONT TestParseSingleRange/malformed_end_before_start2667=== CONT TestParseSingleRange/malformed_both_empty2668=== CONT TestParseSingleRange/unknown_unit2669=== CONT TestParseSingleRange/malformed_no_dash2670=== CONT TestParseSingleRange/multi-range_ignored2671--- PASS: TestParseSingleRange (0.00s)2672 --- PASS: TestParseSingleRange/none (0.00s)2673 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2674 --- PASS: TestParseSingleRange/single_byte (0.00s)2675 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2676 --- PASS: TestParseSingleRange/suffix (0.00s)2677 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2678 --- PASS: TestParseSingleRange/open-ended (0.00s)2679 --- PASS: TestParseSingleRange/closed (0.00s)2680 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2681 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2682 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2683 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2684 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2685 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2686=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info26872026/10/01 09:42:29 INFO Received uploads request method=POST path=/2688=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key26892026/10/01 09:42:29 INFO Received request for more parts method=POST path=/2690=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key26912026/10/01 09:42:29 INFO Received complete multipart upload request method=POST path=/2692=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal26932026/10/01 09:42:29 INFO Received uploads request method=POST path=/2694=== CONT TestIsValidCachePath/narinfo2695=== CONT TestIsValidCachePath/short_hash2696=== CONT TestIsValidCachePath/wrong_extension2697--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2698 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2699 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2700 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2701 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2702=== CONT TestIsValidCachePath/index.html2703=== CONT TestIsValidCachePath/empty2704=== CONT TestIsValidCachePath/leading_slash2705=== CONT TestIsValidCachePath/random_path2706=== CONT TestIsValidCachePath/invalid_char_u2707=== CONT TestIsValidCachePath/nix-cache-info2708=== CONT TestIsValidCachePath/invalid_char_e2709=== CONT TestIsValidCachePath/nar_uncompressed2710=== CONT TestIsValidCachePath/traversal_in_middle2711=== CONT TestIsValidCachePath/log2712=== CONT TestIsValidCachePath/traversal_parent2713=== CONT TestIsValidCachePath/ls2714=== CONT TestIsValidCachePath/nar_zst2715=== CONT TestIsValidCachePath/realisation2716=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2717=== CONT TestIsValidCachePath/nar_xz2718=== CONT TestIsValidCachePath/nar_bz22719--- PASS: TestIsValidCachePath (0.00s)2720 --- PASS: TestIsValidCachePath/narinfo (0.00s)2721 --- PASS: TestIsValidCachePath/short_hash (0.00s)2722 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2723 --- PASS: TestIsValidCachePath/index.html (0.00s)2724 --- PASS: TestIsValidCachePath/empty (0.00s)2725 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2726 --- PASS: TestIsValidCachePath/random_path (0.00s)2727 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2728 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2729 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2730 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2731 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2732 --- PASS: TestIsValidCachePath/log (0.00s)2733 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2734 --- PASS: TestIsValidCachePath/ls (0.00s)2735 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2736 --- PASS: TestIsValidCachePath/realisation (0.00s)2737 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2738 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2739 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2740=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2741=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2742=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected27432026/10/01 09:42:29 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2744=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2745=== CONT TestIsValidUploadKey/narinfo2746=== CONT TestIsValidUploadKey/realisation_plus_in_output27472026/10/01 09:42:29 WARN Authentication failed token_preview=eyJhbGciOi...MmwKI7Y71Q token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2748=== CONT TestIsValidUploadKey/unknown_type2749=== CONT TestIsValidUploadKey/empty_key2750=== CONT TestIsValidUploadKey/traversal_nar2751=== CONT TestIsValidUploadKey/traversal2752=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2753=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2754=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2755=== CONT TestIsValidUploadKey/index.html2756=== CONT TestIsValidUploadKey/nix-cache-info2757=== CONT TestIsValidUploadKey/build_log_home-manager_file2758=== CONT TestIsValidUploadKey/nar_plain2759=== CONT TestIsValidUploadKey/absolute2760=== CONT TestIsValidUploadKey/realisation2761=== CONT TestIsValidUploadKey/build_log2762=== CONT TestIsValidUploadKey/build_log_question_mark2763=== CONT TestIsValidUploadKey/nar_xz2764=== CONT TestIsValidUploadKey/listing2765=== CONT TestIsValidUploadKey/build_log_equals2766=== CONT TestIsValidUploadKey/build_log_plus_in_name2767=== CONT TestService_RequireScope_OIDC/builder_may_write2768=== CONT TestIsValidUploadKey/nar_zst2769--- PASS: TestIsValidUploadKey (0.00s)2770 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2771 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2772 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2773 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2774 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2775 --- PASS: TestIsValidUploadKey/traversal (0.00s)2776 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2777 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2778 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2779 --- PASS: TestIsValidUploadKey/index.html (0.00s)2780 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2781 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2782 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2783 --- PASS: TestIsValidUploadKey/absolute (0.00s)2784 --- PASS: TestIsValidUploadKey/realisation (0.00s)2785 --- PASS: TestIsValidUploadKey/build_log (0.00s)2786 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2787 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2788 --- PASS: TestIsValidUploadKey/listing (0.00s)2789 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2790 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2791 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2792=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2793=== CONT TestService_RequireScope_OIDC/writer_implies_read2794--- PASS: TestService_AuthMiddleware_OIDC (0.51s)2795 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2796 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2797 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2798 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2799=== CONT TestService_RequireScope_OIDC/static_token_may_write2800=== CONT TestService_RequireScope_OIDC/static_token_may_admin2801=== CONT TestService_RequireScope_OIDC/reader_may_read2802=== CONT TestService_RequireScope_OIDC/reader_may_not_write2803=== CONT TestService_RequireScope_OIDC/ops_may_not_write2804=== CONT TestService_RequireScope_OIDC/ops_may_admin2805=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2806--- PASS: TestService_RequireScope_OIDC (0.42s)2807 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2808 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2809 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2810 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2811 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2812 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2813 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2814 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2815 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2816 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)28172026-10-01 09:42:29.814 UTC [1585] ERROR: relation "goose_db_version" does not exist at character 3628182026-10-01 09:42:29.814 UTC [1585] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2819=== NAME TestNARDeduplicationMetadataUploadBug2820 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2368602023/001/store/64llnjkqrs9qssbdkigfdb2x1az6s4gz-file1.txt2821--- PASS: TestReadProxyNarinfo (0.38s)28222026/10/01 09:42:29 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28232026/10/01 09:42:29 OK 20241026095416_initial_model.sql (10.66ms)28242026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)2825--- PASS: TestReadProxyNarStreaming (0.41s)28262026/10/01 09:42:29 OK 20251218171726_add_pins.sql (3.66ms)28272026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)28282026-10-01 09:42:29.841 UTC [1604] ERROR: relation "goose_db_version" does not exist at character 3628292026-10-01 09:42:29.841 UTC [1604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28302026-10-01 09:42:29.844 UTC [1605] ERROR: relation "goose_db_version" does not exist at character 3628312026-10-01 09:42:29.844 UTC [1605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28322026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.8ms)28332026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (8.58ms)28342026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (1.98ms)28352026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000028362026/10/01 09:42:29 OK 1_commit_pending_closure.sql (2.15ms)28372026/10/01 09:42:29 OK 2_object_stats_trigger.sql (1.21ms)28382026/10/01 09:42:29 OK 3_commit_push.sql (1.12ms)28392026/10/01 09:42:29 goose: up to current file version: 328402026/10/01 09:42:29 OK 20241026095416_initial_model.sql (8.16ms)28412026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)28422026-10-01 09:42:29.863 UTC [1625] ERROR: relation "goose_db_version" does not exist at character 3628432026-10-01 09:42:29.863 UTC [1625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28442026/10/01 09:42:29 OK 20241026095416_initial_model.sql (10.96ms)28452026/10/01 09:42:29 OK 20251218171726_add_pins.sql (2.69ms)28462026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)28472026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.13ms)28482026/10/01 09:42:29 OK 20251218171726_add_pins.sql (2.97ms)28492026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.43ms)2850--- PASS: TestGCBugBareHashReferences (0.60s)28512026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)28522026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (1.65ms)28532026/10/01 09:42:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux28542026/10/01 09:42:29 WARN Refused reserved pin name=worker-x86_64-linux28552026/10/01 09:42:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux28562026/10/01 09:42:29 INFO Received create pin request method=POST path=/api/pins/my-app28572026/10/01 09:42:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2858--- PASS: TestCreatePin_ReservedPins (0.45s)28592026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (2.27ms)28602026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000028612026/10/01 09:42:29 OK 20260905000000_add_claims.sql (3.25ms)28622026/10/01 09:42:29 OK 1_commit_pending_closure.sql (1.74ms)28632026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (1.64ms)28642026/10/01 09:42:29 OK 2_object_stats_trigger.sql (779.45µs)28652026/10/01 09:42:29 OK 20241026095416_initial_model.sql (9.72ms)28662026/10/01 09:42:29 OK 3_commit_push.sql (478.56µs)28672026/10/01 09:42:29 goose: up to current file version: 328682026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (1.37ms)28692026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000028702026/10/01 09:42:29 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)28712026/10/01 09:42:29 OK 1_commit_pending_closure.sql (1.34ms)28722026/10/01 09:42:29 OK 2_object_stats_trigger.sql (613.07µs)28732026/10/01 09:42:29 OK 3_commit_push.sql (468.82µs)28742026/10/01 09:42:29 goose: up to current file version: 328752026/10/01 09:42:29 OK 20251218171726_add_pins.sql (2.28ms)28762026/10/01 09:42:29 OK 20260628120000_add_object_size_and_stats.sql (2.71ms)28772026/10/01 09:42:29 INFO Starting HTTP server address=127.0.0.1:4210328782026/10/01 09:42:29 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3953420195/001/proxy.sock28792026/10/01 09:42:29 WARN mTLS auth: subject not in bound subjects subject="CN=someone"28802026/10/01 09:42:29 INFO Shutdown signal received, draining in-flight requests timeout=10s2881--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.39s)28822026/10/01 09:42:29 OK 20260905000000_add_claims.sql (2.34ms)28832026/10/01 09:42:29 OK 20260920000000_drop_claims.sql (1.64ms)28842026/10/01 09:42:29 INFO Received push request method=POST path=/api/pushes28852026/10/01 09:42:29 OK 20260923120000_add_pushes.sql (1.51ms)28862026/10/01 09:42:29 goose: successfully migrated database to version: 2026092312000028872026/10/01 09:42:29 OK 1_commit_pending_closure.sql (1.76ms)28882026/10/01 09:42:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)28892026/10/01 09:42:29 INFO Uploading 64llnjkqrs9qssbdkigfdb2x1az6s4gz-file1.txt (160B)28902026/10/01 09:42:29 OK 2_object_stats_trigger.sql (862.61µs)28912026/10/01 09:42:29 OK 3_commit_push.sql (727.97µs)28922026/10/01 09:42:29 goose: up to current file version: 328932026/10/01 09:42:29 WARN Failed to register uploaded object key=64llnjkqrs9qssbdkigfdb2x1az6s4gz.ls error="server returned 404: 404 page not found\n"28942026/10/01 09:42:29 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"28952026/10/01 09:42:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28962026/10/01 09:42:29 INFO Signed narinfos id=1 count=128972026/10/01 09:42:29 INFO Uploading 1 narinfos28982026/10/01 09:42:29 INFO Received complete push request method=POST path=/api/pushes/1/complete28992026/10/01 09:42:29 WARN Failed to register uploaded object key=64llnjkqrs9qssbdkigfdb2x1az6s4gz.narinfo error="server returned 404: 404 page not found\n"29002026/10/01 09:42:29 INFO Upload complete. (57ms)2901--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.39s)2902=== NAME TestNARDeduplicationMetadataUploadBug2903 metadata_upload_test.go:54: Retrieved narinfo from S3:2904 StorePath: /build/TestNARDeduplicationMetadataUploadBug2368602023/001/store/64llnjkqrs9qssbdkigfdb2x1az6s4gz-file1.txt2905 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2906 Compression: zstd2907 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2908 NarSize: 1602909 References: 2910 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2911 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2912 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2913 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}29142026/10/01 09:42:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.271465ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2915 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2368602023/001/store/2pfmqf19g709b9g9c1kkmia0g47bpfaw-file2.txt2916--- PASS: TestPresentReportsOnlyClosureRoots (0.33s)2917--- PASS: TestObjectStatsTrigger (0.35s)29182026/10/01 09:42:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete29192026/10/01 09:42:29 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=M2M5NmU4YjEtNDkwNy00ZWU4LWIzNWQtYzU0MzAyZTY4NjgzLmVmNWVlNGQ5LTUyYjUtNDVlNC04Y2U3LWRkMTA3ZDY5ZmM5M3gxNzkwODQ3NzQ5Njg4MzQ2Mjgx parts=1029202026/10/01 09:42:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete29212026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures29222026/10/01 09:42:29 INFO Completed upload id=129232026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures29242026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures29252026/10/01 09:42:29 INFO Aborted multipart uploads count=0 kept=029262026/10/01 09:42:29 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo29272026/10/01 09:42:29 WARN Found objects in DB but missing from S3, will re-upload count=12928--- PASS: TestService_verifyS3Integrity (0.69s)29292026/10/01 09:42:29 WARN Force mode enabled - objects will be deleted immediately without grace period29302026/10/01 09:42:29 INFO Received uploads request method=POST path=/api/pending_closures29312026/10/01 09:42:30 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=029322026/10/01 09:42:30 INFO Vacuumed table table=pending_closures29332026/10/01 09:42:30 INFO Vacuumed table table=pending_objects29342026/10/01 09:42:30 INFO Vacuumed table table=multipart_uploads29352026/10/01 09:42:30 INFO Vacuumed table table=closures29362026/10/01 09:42:30 INFO Vacuumed table table=objects29372026/10/01 09:42:30 INFO Aborted multipart uploads count=0 kept=029382026/10/01 09:42:30 WARN Force mode enabled - objects will be deleted immediately without grace period29392026/10/01 09:42:30 INFO Received push request method=POST path=/api/pushes29402026/10/01 09:42:30 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)29412026/10/01 09:42:30 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=029422026/10/01 09:42:30 INFO Vacuumed table table=pending_closures29432026/10/01 09:42:30 INFO Vacuumed table table=pending_objects29442026/10/01 09:42:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign29452026/10/01 09:42:30 INFO Vacuumed table table=multipart_uploads29462026/10/01 09:42:30 INFO Vacuumed table table=closures29472026/10/01 09:42:30 INFO Signed narinfos id=2 count=129482026/10/01 09:42:30 WARN Failed to register uploaded object key=2pfmqf19g709b9g9c1kkmia0g47bpfaw.ls error="server returned 404: 404 page not found\n"29492026/10/01 09:42:30 INFO Uploading 1 narinfos29502026/10/01 09:42:30 INFO Vacuumed table table=objects29512026/10/01 09:42:30 INFO Received complete push request method=POST path=/api/pushes/2/complete29522026/10/01 09:42:30 WARN Failed to register uploaded object key=2pfmqf19g709b9g9c1kkmia0g47bpfaw.narinfo error="server returned 404: 404 page not found\n"29532026/10/01 09:42:30 INFO Upload complete. (46ms)2954=== NAME TestNARDeduplicationMetadataUploadBug2955 metadata_upload_test.go:76: Retrieved narinfo from S3:2956 StorePath: /build/TestNARDeduplicationMetadataUploadBug2368602023/001/store/2pfmqf19g709b9g9c1kkmia0g47bpfaw-file2.txt2957 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2958 Compression: zstd2959 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2960 NarSize: 1602961 References: 2962 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2963 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2964 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2965 {"version":1,"root":{"type":"regular","size":44}}2966--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2967 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.28s)2968 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.28s)2969--- PASS: TestNARDeduplicationMetadataUploadBug (0.63s)29702026/10/01 09:42:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"29712026/10/01 09:42:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.552094ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29722026/10/01 09:42:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2973=== NAME TestOrphanedObjectsGC2974 orphaned_objects_gc_test.go:290: GC Test Summary:2975 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2976 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2977 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2978 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2979 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2980--- PASS: TestOrphanedObjectsGC (0.60s)2981--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.91s)2982--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)2983 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2984 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2985 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.89s)29862026/10/01 09:42:30 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=730.349555ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2987=== NAME TestOrphanedObjectsGCStressTest2988 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2989 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2990 orphaned_objects_gc_test.go:509: Stress test completed successfully:2991 orphaned_objects_gc_test.go:510: - Active objects preserved: 202992 orphaned_objects_gc_test.go:511: - Objects deleted: 2102993 orphaned_objects_gc_test.go:512: - Total GC'd: 2102994--- PASS: TestOrphanedObjectsGCStressTest (1.60s)29952026/10/01 09:42:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.585776166s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29962026/10/01 09:42:31 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=029972026/10/01 09:42:31 INFO Received create pin request method=POST path=/api/pins/myapp29982026/10/01 09:42:31 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1664030140/001/store/plsimj6rycqihalps4518fvwfzpikcww-pinned-file.txt narinfo_key=plsimj6rycqihalps4518fvwfzpikcww.narinfo29992026/10/01 09:42:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures30002026/10/01 09:42:31 INFO Garbage collection started30012026/10/01 09:42:31 INFO Aborted multipart uploads count=0 kept=030022026/10/01 09:42:31 WARN Force mode enabled - objects will be deleted immediately without grace period30032026/10/01 09:42:31 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=030042026/10/01 09:42:31 INFO Vacuumed table table=pending_closures30052026/10/01 09:42:31 INFO Vacuumed table table=pending_objects30062026/10/01 09:42:31 INFO Vacuumed table table=multipart_uploads30072026/10/01 09:42:31 INFO Vacuumed table table=closures30082026/10/01 09:42:31 INFO Vacuumed table table=objects30092026/10/01 09:42:31 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=03010=== NAME TestClientIntegration3011 client_integration_test.go:323: Objects in database after GC:3012 client_integration_test.go:323: Successfully deleted all objects with GC --force3013--- PASS: TestClientIntegration (2.78s)30142026/10/01 09:42:31 WARN Rate limiter enabled after throttle name=s3-test rate=530152026/10/01 09:42:31 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."3016=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle3017 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=103018 throttle_test.go:215: Rate limiter: enabled=true, rate=5.003019--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.99s)30202026/10/01 09:42:32 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30212026/10/01 09:42:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.069852ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30222026/10/01 09:42:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.489602ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config3023=== NAME TestPinProtectsFromGC3024 client_integration_test.go:840: Pin successfully protected closure from garbage collection3025--- PASS: TestPinProtectsFromGC (4.91s)30262026/10/01 09:42:33 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=757.025356ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30272026/10/01 09:42:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.527752599s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30282026/10/01 09:42:35 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"30292026/10/01 09:42:35 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30302026/10/01 09:42:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.277596ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30312026/10/01 09:42:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=396.949472ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30322026/10/01 09:42:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=872.518658ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30332026/10/01 09:42:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.562654704s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30342026/10/01 09:42:39 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30352026/10/01 09:42:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.072149ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30362026/10/01 09:42:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=430.256991ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30372026/10/01 09:42:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=737.884953ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30382026/10/01 09:42:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.443165931s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3039--- PASS: TestClientErrorHandling (0.00s)3040 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)3041 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.34s)3042 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.14s)3043PASS30442026-10-01 09:42:42.122 UTC [129] LOG: received smart shutdown request30452026-10-01 09:42:42.125 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 130462026-10-01 09:42:42.136 UTC [134] LOG: shutting down30472026-10-01 09:42:42.136 UTC [134] LOG: checkpoint starting: shutdown immediate30482026-10-01 09:42:42.965 UTC [134] LOG: checkpoint complete: wrote 10655 buffers (65.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 24 recycled; write=0.178 s, sync=0.624 s, total=0.829 s; sync files=27976, longest=0.002 s, average=0.001 s; distance=387351 kB, estimate=387351 kB; lsn=0/191ABA60, redo lsn=0/191ABA6030492026-10-01 09:42:43.039 UTC [129] LOG: database system is shut down3050Running OIDC tests...3051=== RUN TestAudienceForIssuer3052=== PAUSE TestAudienceForIssuer3053=== RUN TestGlobMatch3054=== PAUSE TestGlobMatch3055=== RUN TestValidateToken_ValidToken3056=== PAUSE TestValidateToken_ValidToken3057=== RUN TestValidateToken_WrongAudience3058=== PAUSE TestValidateToken_WrongAudience3059=== RUN TestValidateToken_Expired3060=== PAUSE TestValidateToken_Expired3061=== RUN TestValidateToken_BoundClaimsMismatch3062=== PAUSE TestValidateToken_BoundClaimsMismatch3063=== RUN TestValidateToken_BoundSubjectMismatch3064=== PAUSE TestValidateToken_BoundSubjectMismatch3065=== RUN TestValidateToken_MultipleProviders3066=== PAUSE TestValidateToken_MultipleProviders3067=== RUN TestValidateToken_NoMatchingProvider3068=== PAUSE TestValidateToken_NoMatchingProvider3069=== RUN TestValidateToken_KubernetesServiceAccount3070=== PAUSE TestValidateToken_KubernetesServiceAccount3071=== RUN TestNewValidator_KubernetesRequiresCA3072=== PAUSE TestNewValidator_KubernetesRequiresCA3073=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3074=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3075=== RUN TestPins_ReservedForMatchingRule3076=== PAUSE TestPins_ReservedForMatchingRule3077=== RUN TestPins_TopLevelShorthand3078=== PAUSE TestPins_TopLevelShorthand3079=== RUN TestPins_ConfigValidation3080=== PAUSE TestPins_ConfigValidation3081=== RUN TestScopes_LegacyProviderDefaultsToWrite3082=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3083=== RUN TestScopes_Rules3084=== PAUSE TestScopes_Rules3085=== RUN TestScopes_ConfigValidation3086=== PAUSE TestScopes_ConfigValidation3087=== CONT TestAudienceForIssuer3088=== CONT TestValidateToken_BoundClaimsMismatch3089--- PASS: TestAudienceForIssuer (0.00s)3090=== CONT TestValidateToken_KubernetesServiceAccount3091=== CONT TestValidateToken_Expired3092=== CONT TestValidateToken_WrongAudience3093=== CONT TestValidateToken_ValidToken3094=== CONT TestGlobMatch3095=== RUN TestGlobMatch/foo_foo3096=== PAUSE TestGlobMatch/foo_foo3097=== RUN TestGlobMatch/foo_bar3098=== PAUSE TestGlobMatch/foo_bar3099=== RUN TestGlobMatch/*_3100=== PAUSE TestGlobMatch/*_3101=== RUN TestGlobMatch/*_anything3102=== CONT TestValidateToken_BoundSubjectMismatch3103=== CONT TestPins_ConfigValidation3104=== CONT TestScopes_ConfigValidation3105=== CONT TestScopes_Rules3106=== CONT TestScopes_LegacyProviderDefaultsToWrite3107=== CONT TestValidateToken_NoMatchingProvider3108=== CONT TestPins_ReservedForMatchingRule3109=== CONT TestPins_TopLevelShorthand3110=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3111=== CONT TestNewValidator_KubernetesRequiresCA3112=== CONT TestValidateToken_MultipleProviders3113=== PAUSE TestGlobMatch/*_anything3114=== RUN TestGlobMatch/foo*_foo3115=== PAUSE TestGlobMatch/foo*_foo3116=== RUN TestGlobMatch/foo*_foobar3117=== PAUSE TestGlobMatch/foo*_foobar3118=== RUN TestGlobMatch/foo*_bar3119=== PAUSE TestGlobMatch/foo*_bar3120=== RUN TestGlobMatch/*bar_bar3121=== PAUSE TestGlobMatch/*bar_bar3122=== RUN TestGlobMatch/*bar_foobar3123=== PAUSE TestGlobMatch/*bar_foobar3124=== RUN TestGlobMatch/*bar_foo3125=== PAUSE TestGlobMatch/*bar_foo3126=== RUN TestGlobMatch/foo*bar_foobar3127=== PAUSE TestGlobMatch/foo*bar_foobar3128=== RUN TestGlobMatch/foo*bar_foo123bar3129=== PAUSE TestGlobMatch/foo*bar_foo123bar3130=== RUN TestGlobMatch/foo*bar_foobarbaz3131=== PAUSE TestGlobMatch/foo*bar_foobarbaz3132=== RUN TestGlobMatch/*/*_foo/bar3133=== PAUSE TestGlobMatch/*/*_foo/bar3134=== RUN TestGlobMatch/*/*_foo3135=== PAUSE TestGlobMatch/*/*_foo3136=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3137=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3138=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03139=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03140=== RUN TestGlobMatch/refs/*/main_refs/heads/main3141=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3142=== RUN TestGlobMatch/fo?_foo3143=== PAUSE TestGlobMatch/fo?_foo3144=== RUN TestGlobMatch/fo?_fo3145=== PAUSE TestGlobMatch/fo?_fo3146=== RUN TestGlobMatch/fo?_fooo3147=== PAUSE TestGlobMatch/fo?_fooo3148=== RUN TestGlobMatch/?oo_foo3149=== PAUSE TestGlobMatch/?oo_foo3150=== RUN TestGlobMatch/?oo_boo3151=== PAUSE TestGlobMatch/?oo_boo3152=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3153=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3154=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3155=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3156=== CONT TestGlobMatch/foo_foo3157=== CONT TestGlobMatch/*/*_foo3158=== CONT TestGlobMatch/?oo_foo3159=== CONT TestGlobMatch/*bar_bar3160=== CONT TestGlobMatch/*bar_foo3161=== CONT TestGlobMatch/foo*bar_foobar3162=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3163=== CONT TestGlobMatch/foo*bar_foo123bar3164=== CONT TestGlobMatch/*/*_foo/bar3165=== CONT TestGlobMatch/?oo_boo3166=== CONT TestGlobMatch/*_3167=== CONT TestGlobMatch/*_anything3168=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3169=== CONT TestGlobMatch/foo_bar3170=== CONT TestGlobMatch/*bar_foobar3171=== CONT TestGlobMatch/foo*_foobar3172=== CONT TestGlobMatch/foo*bar_foobarbaz3173=== CONT TestGlobMatch/foo*_bar3174=== CONT TestGlobMatch/foo*_foo3175=== CONT TestGlobMatch/fo?_foo3176=== CONT TestGlobMatch/fo?_fooo3177=== CONT TestGlobMatch/fo?_fo3178=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03179=== CONT TestGlobMatch/refs/*/main_refs/heads/main3180=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3181--- PASS: TestPins_ConfigValidation (0.00s)3182--- PASS: TestGlobMatch (0.00s)3183 --- PASS: TestGlobMatch/foo_foo (0.00s)3184 --- PASS: TestGlobMatch/*/*_foo (0.00s)3185 --- PASS: TestGlobMatch/?oo_foo (0.00s)3186 --- PASS: TestGlobMatch/*bar_bar (0.00s)3187 --- PASS: TestGlobMatch/*bar_foo (0.00s)3188 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3189 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3190 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3191 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3192 --- PASS: TestGlobMatch/?oo_boo (0.00s)3193 --- PASS: TestGlobMatch/*_ (0.00s)3194 --- PASS: TestGlobMatch/*_anything (0.00s)3195 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3196 --- PASS: TestGlobMatch/foo_bar (0.00s)3197 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3198 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3199 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3200 --- PASS: TestGlobMatch/foo*_bar (0.00s)3201 --- PASS: TestGlobMatch/foo*_foo (0.00s)3202 --- PASS: TestGlobMatch/fo?_foo (0.00s)3203 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3204 --- PASS: TestGlobMatch/fo?_fo (0.00s)3205 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3206 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3207 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3208--- PASS: TestScopes_ConfigValidation (0.00s)32092026/10/01 09:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43287/oidc3210--- PASS: TestPins_ReservedForMatchingRule (0.05s)32112026/10/01 09:42:44 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:400453212--- PASS: TestValidateToken_KubernetesServiceAccount (0.08s)32132026/10/01 09:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44171/oidc3214--- PASS: TestValidateToken_ValidToken (0.09s)32152026/10/01 09:42:44 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12332162026/10/01 09:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40573/oidc3217--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)3218--- PASS: TestScopes_Rules (0.11s)32192026/10/01 09:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44141/oidc3220--- PASS: TestValidateToken_BoundClaimsMismatch (0.12s)32212026/10/01 09:42:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42489/oidc32222026/10/01 09:42:44 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40739/oidc3223--- PASS: TestValidateToken_MultipleProviders (0.13s)32242026/10/01 09:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38877/oidc3225--- PASS: TestValidateToken_WrongAudience (0.17s)32262026/10/01 09:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45823/oidc3227--- PASS: TestValidateToken_BoundSubjectMismatch (0.17s)32282026/10/01 09:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38289/oidc3229--- PASS: TestPins_TopLevelShorthand (0.18s)32302026/10/01 09:42:44 http: TLS handshake error from 127.0.0.1:52990: remote error: tls: bad certificate3231--- PASS: TestNewValidator_KubernetesRequiresCA (0.19s)32322026/10/01 09:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43147/oidc3233--- PASS: TestValidateToken_Expired (0.22s)32342026/10/01 09:42:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37365/oidc3235--- PASS: TestValidateToken_NoMatchingProvider (0.27s)32362026/10/01 09:42:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40337/oidc3237--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.32s)3238PASS3239Running hook tests...3240=== RUN TestSendPathsEmpty3241=== PAUSE TestSendPathsEmpty3242=== RUN TestQueueEnqueueAndFetch3243=== PAUSE TestQueueEnqueueAndFetch3244=== RUN TestQueueDeduplication3245=== PAUSE TestQueueDeduplication3246=== RUN TestQueueRemove3247=== PAUSE TestQueueRemove3248=== RUN TestQueueFetchBatchLimit3249=== PAUSE TestQueueFetchBatchLimit3250=== RUN TestQueueRetryMovesToBack3251=== PAUSE TestQueueRetryMovesToBack3252=== RUN TestQueueFetchRemoveLifecycle3253=== PAUSE TestQueueFetchRemoveLifecycle3254=== RUN TestQueueConcurrentWriters3255=== PAUSE TestQueueConcurrentWriters3256=== RUN TestQueueRemoveLargeClosure3257=== PAUSE TestQueueRemoveLargeClosure3258=== RUN TestServerClientIntegration3259=== PAUSE TestServerClientIntegration3260=== RUN TestServerQueueError3261=== PAUSE TestServerQueueError3262=== RUN TestGetListenerSocketActivation3263 server_test.go:210: === RUN TestGetListenerSocketActivation3264 --- PASS: TestGetListenerSocketActivation (0.00s)3265 PASS3266 3267--- PASS: TestGetListenerSocketActivation (0.01s)3268=== RUN TestDrainIsolatesPoisonPath3269=== PAUSE TestDrainIsolatesPoisonPath3270=== RUN TestRunNotBlockedByPoisonHead3271=== PAUSE TestRunNotBlockedByPoisonHead3272=== RUN TestDrainGivesUpWhenServerDown3273=== PAUSE TestDrainGivesUpWhenServerDown3274=== RUN TestFailedPathPrunedByLaterClosure3275=== PAUSE TestFailedPathPrunedByLaterClosure3276=== RUN TestWorkerUploadsAndRemoves3277=== PAUSE TestWorkerUploadsAndRemoves3278=== RUN TestWorkerSkipsGCdPaths3279=== PAUSE TestWorkerSkipsGCdPaths3280=== RUN TestWorkerPrunesClosureDeps3281=== PAUSE TestWorkerPrunesClosureDeps3282=== RUN TestDrainTimeout3283=== PAUSE TestDrainTimeout3284=== CONT TestSendPathsEmpty3285=== CONT TestRunNotBlockedByPoisonHead3286=== CONT TestFailedPathPrunedByLaterClosure3287=== CONT TestDrainGivesUpWhenServerDown3288=== CONT TestDrainIsolatesPoisonPath3289=== CONT TestServerQueueError3290=== CONT TestServerClientIntegration3291=== CONT TestQueueRemoveLargeClosure3292=== CONT TestQueueConcurrentWriters3293=== CONT TestQueueFetchRemoveLifecycle3294=== CONT TestQueueRetryMovesToBack3295=== CONT TestQueueFetchBatchLimit3296=== CONT TestQueueRemove3297=== CONT TestWorkerSkipsGCdPaths3298=== CONT TestQueueDeduplication3299=== CONT TestQueueEnqueueAndFetch33002026/10/01 09:42:44 ERROR Failed to queue paths error="permission denied" count=13301=== CONT TestDrainTimeout3302=== CONT TestWorkerPrunesClosureDeps3303=== CONT TestWorkerUploadsAndRemoves3304--- PASS: TestSendPathsEmpty (0.00s)3305--- PASS: TestServerQueueError (0.00s)3306--- PASS: TestServerClientIntegration (0.00s)3307--- PASS: TestQueueEnqueueAndFetch (0.01s)33082026/10/01 09:42:44 INFO Uploading batch count=133092026/10/01 09:42:44 ERROR Upload failed error="upload failed" count=133102026/10/01 09:42:44 INFO Uploading batch count=433112026/10/01 09:42:44 ERROR Upload failed error="upload failed" count=433122026/10/01 09:42:44 INFO Uploading batch count=233132026/10/01 09:42:44 INFO Uploading batch count=233142026/10/01 09:42:44 ERROR Upload failed error="upload failed" count=233152026/10/01 09:42:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1297721945/002/a33162026/10/01 09:42:44 INFO Upload queue status pending=333172026/10/01 09:42:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1297721945/002/b33182026/10/01 09:42:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3313467529/002/bbb33192026/10/01 09:42:44 INFO Uploading batch count=133202026/10/01 09:42:44 INFO Uploading batch count=133212026/10/01 09:42:44 INFO Upload queue status pending=233222026/10/01 09:42:44 ERROR Upload failed error="upload failed" count=133232026/10/01 09:42:44 INFO Uploading batch count=233242026/10/01 09:42:44 INFO Upload queue status pending=233252026/10/01 09:42:44 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1607684915/002/nonexistent33262026/10/01 09:42:44 INFO Upload queue status pending=23327--- PASS: TestQueueDeduplication (0.01s)3328--- PASS: TestQueueFetchRemoveLifecycle (0.01s)33292026/10/01 09:42:44 INFO Uploading batch count=133302026/10/01 09:42:44 INFO Uploading batch count=13331--- PASS: TestQueueRemove (0.01s)3332--- PASS: TestQueueFetchBatchLimit (0.01s)33332026/10/01 09:42:44 INFO Uploading batch count=233342026/10/01 09:42:44 ERROR Upload failed error="upload failed" count=233352026/10/01 09:42:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1297721945/002/c33362026/10/01 09:42:44 INFO Uploading batch count=13337--- PASS: TestQueueRetryMovesToBack (0.01s)33382026/10/01 09:42:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1297721945/002/d33392026/10/01 09:42:44 INFO Uploading batch count=133402026/10/01 09:42:44 ERROR Upload failed error="upload failed" count=133412026/10/01 09:42:44 INFO Uploading batch count=233422026/10/01 09:42:44 ERROR Upload failed error="upload failed" count=233432026/10/01 09:42:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1297721945/002/e33442026/10/01 09:42:44 INFO Uploading batch count=133452026/10/01 09:42:44 ERROR Upload failed error="upload failed" count=133462026/10/01 09:42:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1297721945/002/f33472026/10/01 09:42:44 INFO Uploading batch count=133482026/10/01 09:42:44 ERROR Upload failed error="upload failed" count=133492026/10/01 09:42:44 ERROR Drain finished with paths left in queue remaining=1033502026/10/01 09:42:44 ERROR Drain finished with paths left in queue remaining=13351--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)3352--- PASS: TestDrainIsolatesPoisonPath (0.02s)3353--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3354--- PASS: TestWorkerUploadsAndRemoves (0.03s)3355--- PASS: TestWorkerPrunesClosureDeps (0.03s)3356--- PASS: TestWorkerSkipsGCdPaths (0.03s)3357--- PASS: TestQueueRemoveLargeClosure (0.14s)3358--- PASS: TestQueueConcurrentWriters (0.21s)33592026/10/01 09:42:44 ERROR Upload failed error="context deadline exceeded" count=233602026/10/01 09:42:44 ERROR Drain finished with paths left in queue remaining=43361--- PASS: TestDrainTimeout (0.21s)33622026/10/01 09:42:45 INFO Uploading batch count=133632026/10/01 09:42:45 INFO Uploading batch count=133642026/10/01 09:42:45 INFO Uploading batch count=133652026/10/01 09:42:45 ERROR Upload failed error="upload failed" count=133662026/10/01 09:42:45 INFO Uploading batch count=133672026/10/01 09:42:45 ERROR Upload failed error="upload failed" count=133682026/10/01 09:42:45 INFO Uploading batch count=133692026/10/01 09:42:45 ERROR Upload failed error="upload failed" count=133702026/10/01 09:42:45 INFO Uploading batch count=133712026/10/01 09:42:45 ERROR Upload failed error="upload failed" count=133722026/10/01 09:42:45 ERROR Drain finished with paths left in queue remaining=13373--- PASS: TestRunNotBlockedByPoisonHead (1.03s)3374PASS