niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #270
· 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 TestScriptTokenEmptyCommand97=== CONT TestSetClientTLSErrors98--- PASS: TestScriptTokenEmptyCommand (0.00s)99=== CONT TestSetClientTLSDoesNotMutateDefaultTransport100=== CONT TestSetClientTLS101=== CONT TestClientSignaturesByStorePath102--- PASS: TestClientSignaturesByStorePath (0.00s)103=== CONT TestScriptTokenBadJSON104=== CONT TestStreamPushReportsSignatures105=== CONT TestStreamPushRequestLine106=== CONT TestStreamPushGivesUpOnDeadServer107=== CONT TestStreamPushIsolatesFailures1082026/09/23 13:34:08 ERROR Upload failed error="bad path" count=3109=== CONT TestStreamPushBatchesUnderLoad110=== CONT TestStreamPushReportsEveryPath111=== CONT TestShellSplitErrors112=== CONT TestEncodeNixBase32WithRealHash1132026/09/23 13:34:08 ERROR Upload failed error="connection refused" count=201142026/09/23 13:34:08 ERROR Server seems unavailable, giving up on batch untried=17115=== CONT TestDoWithRetry_BodyReplayedViaGetBody116=== CONT TestUploadMultipart_SupersededByPeer1172026/09/23 13:34:08 ERROR Upload failed error=boom count=1118=== CONT TestResolveStorePath119=== CONT TestDumpPathWriterError120=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1212026/09/23 13:34:08 ERROR Upload failed error=boom count=1122=== CONT TestRateLimiterFeedback123=== CONT TestPathInfoCACompatibility1242026/09/23 13:34:08 WARN Rate limiter enabled after throttle name=server-test rate=5125=== CONT TestDumpPathSingleFile126=== RUN TestRateLimiterFeedback/429_enables_limiter127=== CONT TestParsePathInfoJSON128=== CONT TestPathInfoHashCompatibility129=== CONT TestGetStorePathHash130=== CONT TestConvertHashToNix32131=== CONT TestShellSplit132--- PASS: TestShellSplitErrors (0.00s)133--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)134=== CONT TestScriptTokenScriptFails135=== CONT TestFileTokenMissing136=== RUN TestSetClientTLSErrors/missing_cert_file137=== CONT TestFileTokenEmpty138=== CONT TestEncodeNixBase32139=== RUN TestUploadMultipart_SupersededByPeer/exists140=== RUN TestPathInfoCACompatibility/null_ca_field141=== CONT TestParsePathInfoJSONMultiplePaths142--- PASS: TestEncodeNixBase32WithRealHash (0.00s)143--- PASS: TestScriptTokenBadJSON (0.00s)144--- PASS: TestStreamPushIsolatesFailures (0.00s)145--- PASS: TestStreamPushReportsSignatures (0.00s)146--- PASS: TestStreamPushReportsEveryPath (0.00s)147--- PASS: TestShellSplit (0.00s)148=== PAUSE TestRateLimiterFeedback/429_enables_limiter149=== RUN TestRateLimiterFeedback/503_enables_limiter150=== RUN TestParsePathInfoJSON/Nix_format151=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)152=== RUN TestGetStorePathHash/valid_store_path153=== RUN TestConvertHashToNix32/SRI_format_to_Nix32154=== CONT TestDumpPathMatchesNix155=== PAUSE TestSetClientTLSErrors/missing_cert_file156=== RUN TestEncodeNixBase32/test_string_hash157=== PAUSE TestPathInfoCACompatibility/null_ca_field158=== PAUSE TestUploadMultipart_SupersededByPeer/exists159=== PAUSE TestRateLimiterFeedback/503_enables_limiter160=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter161=== PAUSE TestParsePathInfoJSON/Nix_format162=== RUN TestParsePathInfoJSON/Lix_format163--- PASS: TestResolveStorePath (0.00s)164=== CONT TestFilterOversizedClosures165=== RUN TestFilterOversizedClosures/no_limit_keeps_everything166--- PASS: TestFileTokenMissing (0.00s)167--- PASS: TestFileTokenEmpty (0.00s)168=== CONT TestUploadMultipart_PartsInParallel169--- PASS: TestScriptTokenScriptFails (0.00s)170=== CONT TestScriptTokenEmptyToken171=== CONT TestPartSizeForNAR172=== PAUSE TestGetStorePathHash/valid_store_path173=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)174=== RUN TestGetStorePathHash/basename_without_hyphen_should_error175=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter1762026/09/23 13:34:08 WARN Rate limiter enabled after throttle name=server-test rate=5177=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon178=== RUN TestUploadMultipart_SupersededByPeer/missing179=== PAUSE TestUploadMultipart_SupersededByPeer/missing180=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32181=== RUN TestPathInfoCACompatibility/old_string_format_-_text182=== RUN TestSetClientTLSErrors/missing_key_file1832026/09/23 13:34:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:38261184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text185=== RUN TestSetClientTLS/rejects_connection_without_client_cert186=== PAUSE TestSetClientTLSErrors/missing_key_file187=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive188=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths189=== PAUSE TestParsePathInfoJSON/Lix_format190=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything191=== PAUSE TestEncodeNixBase32/test_string_hash192=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter193--- PASS: TestDoServerRequestAttachesToken (0.01s)194=== CONT TestScriptTokenCachesUntilRefresh195=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon196=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error197=== CONT TestCaseHackSuffix198=== RUN TestConvertHashToNix32/already_Nix32_format199=== RUN TestPartSizeForNAR/zero_stays_at_minimum200=== RUN TestSetClientTLSErrors/missing_ca_file201=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert202=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive203=== CONT TestFileTokenReadsAndCaches204--- PASS: TestScriptTokenEmptyToken (0.00s)205=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2062026/09/23 13:34:08 WARN Rate limiter backed off name=server-test rate=5207=== RUN TestParsePathInfoJSON/empty_input2082026/09/23 13:34:08 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:38261209--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.04s)210=== PAUSE TestParsePathInfoJSON/empty_input211=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths212=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum213=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI214=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI215=== PAUSE TestConvertHashToNix32/already_Nix32_format216=== RUN TestConvertHashToNix32/invalid_format217=== PAUSE TestConvertHashToNix32/invalid_format218=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped219=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped220=== PAUSE TestSetClientTLSErrors/missing_ca_file221=== RUN TestSetClientTLSErrors/invalid_ca_file222=== PAUSE TestSetClientTLSErrors/invalid_ca_file223=== RUN TestPathInfoCACompatibility/new_structured_format_-_text224=== CONT TestUploadMultipart_SupersededByPeer/exists225=== CONT TestUploadMultipart_SupersededByPeer/missing226=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text227=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method228=== CONT TestConvertHashToNix32/SRI_format_to_Nix32229=== RUN TestEncodeNixBase32/empty_input230=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA231=== PAUSE TestEncodeNixBase32/empty_input232=== RUN TestSetClientTLS/preserves_debug_logging_transport233=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter234=== PAUSE TestSetClientTLS/preserves_debug_logging_transport235=== CONT TestRegisterUploadedObjectReusesConnections236=== RUN TestParsePathInfoJSON/whitespace_only237=== PAUSE TestParsePathInfoJSON/whitespace_only238=== RUN TestParsePathInfoJSON/invalid_JSON239=== PAUSE TestParsePathInfoJSON/invalid_JSON240=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths241=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths242=== RUN TestPartSizeForNAR/small_stays_at_minimum243=== CONT TestSetClientTLSErrors/invalid_ca_file244=== CONT TestEncodeNixBase32/test_string_hash245=== CONT TestEncodeNixBase32/empty_input246=== CONT TestRateLimiterFeedback/429_enables_limiter247=== PAUSE TestPartSizeForNAR/small_stays_at_minimum248=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum249=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum250=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts251=== CONT TestStaticToken252--- PASS: TestDumpPathSingleFile (0.04s)253=== CONT TestScriptTokenNoExpiryRerunsEveryCall254=== RUN TestFilterOversizedClosures/all_closures_skipped255=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error256=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method257=== CONT TestConvertHashToNix32/invalid_format258=== CONT TestConvertHashToNix32/already_Nix32_format259=== CONT TestSetClientTLSErrors/missing_cert_file260=== CONT TestSetClientTLSErrors/missing_ca_file261=== CONT TestSetClientTLSErrors/missing_key_file262=== CONT TestRateLimiterFeedback/503_enables_limiter263=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2642026/09/23 13:34:08 WARN Rate limiter enabled after throttle name=server-test rate=5265=== PAUSE TestFilterOversizedClosures/all_closures_skipped2662026/09/23 13:34:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:45845267=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error268=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error269=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error270=== CONT TestSetClientTLS/rejects_connection_without_client_cert271=== CONT TestParsePathInfoJSON/whitespace_only272=== CONT TestParsePathInfoJSON/invalid_JSON2732026/09/23 13:34:08 WARN Rate limiter backed off name=server-test rate=5274=== CONT TestParsePathInfoJSON/Lix_format2752026/09/23 13:34:08 WARN Rate limiter enabled after throttle name=server-test rate=5276=== CONT TestParsePathInfoJSON/empty_input2772026/09/23 13:34:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:38715278=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths279=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2802026/09/23 13:34:08 WARN Rate limiter backed off name=server-test rate=5281=== CONT TestPathInfoCACompatibility/null_ca_field282=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method283=== CONT TestGetStorePathHash/valid_store_path284=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2852026/09/23 13:34:08 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=2000286=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error287=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive288=== CONT TestPathInfoCACompatibility/new_structured_format_-_text289=== CONT TestSetClientTLS/preserves_debug_logging_transport290=== CONT TestParsePathInfoJSON/Nix_format291=== CONT TestFilterOversizedClosures/all_closures_skipped2922026/09/23 13:34:08 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=50293=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error294=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter295=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter296=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512297=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512298=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)299=== CONT TestFilterOversizedClosures/no_limit_keeps_everything300=== CONT TestGetStorePathHash/basename_without_hyphen_should_error301--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)302--- PASS: TestFileTokenReadsAndCaches (0.00s)303=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512304=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI305=== CONT TestPathInfoCACompatibility/old_string_format_-_text306=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts307=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon308=== RUN TestPartSizeForNAR/1_TiB309--- PASS: TestStaticToken (0.00s)310--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)311 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)312 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)313=== PAUSE TestPartSizeForNAR/1_TiB314=== RUN TestPartSizeForNAR/5_TiB_S3_max_object315=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object316=== RUN TestPartSizeForNAR/capped_at_5_GiB317=== PAUSE TestPartSizeForNAR/capped_at_5_GiB318=== CONT TestPartSizeForNAR/zero_stays_at_minimum319=== CONT TestPartSizeForNAR/capped_at_5_GiB320=== CONT TestPartSizeForNAR/5_TiB_S3_max_object321=== CONT TestPartSizeForNAR/1_TiB322=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts323=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum324=== CONT TestPartSizeForNAR/small_stays_at_minimum325--- PASS: TestPartSizeForNAR (0.04s)326 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)327 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)328 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)329 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)330 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)331 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)332 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)333--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)334 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)335 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)336--- PASS: TestConvertHashToNix32 (0.04s)337 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)338 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)339 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)340--- PASS: TestPathInfoCACompatibility (0.04s)341 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)342 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)343 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)344 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)345 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)346--- PASS: TestParsePathInfoJSON (0.04s)347 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)348 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)349 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)350 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)351 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)352--- PASS: TestPathInfoHashCompatibility (0.04s)353 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)354 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)355 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)356 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)357--- PASS: TestFilterOversizedClosures (0.04s)358 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)359 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)360 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)361--- PASS: TestEncodeNixBase32 (0.04s)362 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)363 --- PASS: TestEncodeNixBase32/empty_input (0.00s)364--- PASS: TestRateLimiterFeedback (0.04s)365 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)366 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)367 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)369--- PASS: TestSetClientTLSErrors (0.04s)370 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)371 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)372 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)373 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)374--- PASS: TestGetStorePathHash (0.04s)375 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)376 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)377 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)378 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)379--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)380--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)3812026/09/23 13:34:08 http: TLS handshake error from 127.0.0.1:49800: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.05s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)387--- PASS: TestCaseHackSuffix (0.06s)388--- PASS: TestStreamPushRequestLine (0.07s)389--- PASS: TestDumpPathWriterError (0.09s)390--- PASS: TestStreamPushBatchesUnderLoad (0.11s)391--- PASS: TestDumpPathMatchesNix (0.13s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)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/postgres2817657044/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/postgres2817657044/data -l logfile start422423/build/postgres2817657044:5432 - no response4242026-09-23 13:34:10.150 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-23 13:34:10.150 UTC [128] LOG: listening on Unix socket "/build/postgres2817657044/.s.PGSQL.5432"4262026-09-23 13:34:10.155 UTC [135] LOG: database system was shut down at 2026-09-23 13:34:09 UTC4272026-09-23 13:34:10.158 UTC [128] LOG: database system is ready to accept connections428/build/postgres2817657044:5432 - accepting connections429{"timestamp":"2026-09-23T13:34:10.35117336Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a9a28b5c-31aa-466a-b9d6-ab1d20aa9c4f","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(199)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestResolveDBConnectionString463=== PAUSE TestResolveDBConnectionString464=== RUN TestLeadElectsOneAndHandsOver465=== PAUSE TestLeadElectsOneAndHandsOver466=== RUN TestLeadIncumbentWinsAfterRestart4672026-09-23 13:34:10.548 UTC [374] ERROR: relation "goose_db_version" does not exist at character 364682026-09-23 13:34:10.548 UTC [374] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4692026/09/23 13:34:10 OK 20241026095416_initial_model.sql (12.46ms)4702026/09/23 13:34:10 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)4712026/09/23 13:34:10 OK 20251218171726_add_pins.sql (3.17ms)4722026/09/23 13:34:10 OK 20260628120000_add_object_size_and_stats.sql (2.89ms)4732026/09/23 13:34:10 OK 20260905000000_add_claims.sql (3.32ms)4742026/09/23 13:34:10 OK 20260920000000_drop_claims.sql (1.96ms)4752026/09/23 13:34:10 OK 20260923120000_add_pushes.sql (1.34ms)4762026/09/23 13:34:10 goose: successfully migrated database to version: 202609231200004772026/09/23 13:34:10 OK 1_commit_pending_closure.sql (1.68ms)4782026/09/23 13:34:10 OK 2_object_stats_trigger.sql (782.37µs)4792026/09/23 13:34:10 OK 3_commit_push.sql (686.61µs)4802026/09/23 13:34:10 goose: up to current file version: 34812026/09/23 13:34:10 INFO lead: acquired remote=192.0.2.1:12344822026/09/23 13:34:11 INFO lead: released remote=192.0.2.1:12344832026/09/23 13:34:11 INFO lead: acquired remote=192.0.2.1:12344842026/09/23 13:34:11 INFO lead: released remote=192.0.2.1:1234485--- PASS: TestLeadIncumbentWinsAfterRestart (0.81s)486=== RUN TestLeadEndsOnShutdown487=== PAUSE TestLeadEndsOnShutdown488=== RUN TestGCAdvisoryLockBlocksConcurrentRun4892026-09-23 13:34:11.321 UTC [384] ERROR: relation "goose_db_version" does not exist at character 364902026-09-23 13:34:11.321 UTC [384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4912026/09/23 13:34:11 OK 20241026095416_initial_model.sql (9.85ms)4922026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)4932026/09/23 13:34:11 OK 20251218171726_add_pins.sql (3.3ms)4942026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)4952026/09/23 13:34:11 OK 20260905000000_add_claims.sql (2.63ms)4962026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (1.64ms)4972026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (1.29ms)4982026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200004992026/09/23 13:34:11 OK 1_commit_pending_closure.sql (1.62ms)5002026/09/23 13:34:11 OK 2_object_stats_trigger.sql (742.87µs)5012026/09/23 13:34:11 OK 3_commit_push.sql (739.31µs)5022026/09/23 13:34:11 goose: up to current file version: 3503--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)504=== RUN TestGCBugBareHashReferences505=== PAUSE TestGCBugBareHashReferences506=== RUN TestGCMetrics507=== PAUSE TestGCMetrics508=== RUN TestGCTaskStore_StartNew509=== PAUSE TestGCTaskStore_StartNew510=== RUN TestGCTaskStore_DeduplicateSameParams511=== PAUSE TestGCTaskStore_DeduplicateSameParams512=== RUN TestGCTaskStore_ConflictDifferentParams513=== PAUSE TestGCTaskStore_ConflictDifferentParams514=== RUN TestGCTaskStore_GetEmpty515=== PAUSE TestGCTaskStore_GetEmpty516=== RUN TestGCTaskStore_GetReturnsLatest517=== PAUSE TestGCTaskStore_GetReturnsLatest518=== RUN TestGCTaskStore_CompletedAllowsNewTask519=== PAUSE TestGCTaskStore_CompletedAllowsNewTask520=== RUN TestGCTaskStore_PhaseUpdates521=== PAUSE TestGCTaskStore_PhaseUpdates522=== RUN TestGCTaskStore_Fail523=== PAUSE TestGCTaskStore_Fail524=== RUN TestGracefulShutdownDrainsInflight525=== PAUSE TestGracefulShutdownDrainsInflight526=== RUN TestService_healthCheckHandler527=== PAUSE TestService_healthCheckHandler528=== RUN TestService_readinessHandler529=== PAUSE TestService_readinessHandler530=== RUN TestGenerateLandingPage531=== PAUSE TestGenerateLandingPage532=== RUN TestCacheConfigHandlerMaxNarSize533=== PAUSE TestCacheConfigHandlerMaxNarSize534=== RUN TestCreatePendingClosureRejectsOversizedNAR535=== PAUSE TestCreatePendingClosureRejectsOversizedNAR536=== RUN TestNARDeduplicationMetadataUploadBug537=== PAUSE TestNARDeduplicationMetadataUploadBug538=== RUN TestMetricsInventory539=== PAUSE TestMetricsInventory540=== RUN TestService_NativeMTLS541=== PAUSE TestService_NativeMTLS542=== RUN TestServerTLSConfig543=== PAUSE TestServerTLSConfig544=== RUN TestMultipartCleanup545=== PAUSE TestMultipartCleanup546=== RUN TestObjectStatsTrigger547=== PAUSE TestObjectStatsTrigger548=== RUN TestOrphanedObjectsGC549=== PAUSE TestOrphanedObjectsGC550=== RUN TestOrphanedObjectsGCStressTest551=== PAUSE TestOrphanedObjectsGCStressTest552=== RUN TestResurrectedObjectNotDeleted553=== PAUSE TestResurrectedObjectNotDeleted554=== RUN TestCreatePin_ReservedPins555=== PAUSE TestCreatePin_ReservedPins556=== RUN TestParseSingleRange557=== PAUSE TestParseSingleRange558=== RUN TestProxyHeadersOnlyTrustedOnSocket559=== PAUSE TestProxyHeadersOnlyTrustedOnSocket560=== RUN TestIsValidCachePath561=== PAUSE TestIsValidCachePath562=== RUN TestReadProxyNarinfo563=== PAUSE TestReadProxyNarinfo564=== RUN TestReadProxyNarinfoAlreadyDecompressed565=== PAUSE TestReadProxyNarinfoAlreadyDecompressed566=== RUN TestReadProxyNarStreaming567=== PAUSE TestReadProxyNarStreaming568=== RUN TestReadProxy404569=== PAUSE TestReadProxy404570=== RUN TestReadProxyInvalidPath571=== PAUSE TestReadProxyInvalidPath572=== RUN TestReadProxyHead573=== PAUSE TestReadProxyHead574=== RUN TestReadProxyConditionalGet575=== PAUSE TestReadProxyConditionalGet576=== RUN TestReadProxyRootRedirectsToIndexHTML577=== PAUSE TestReadProxyRootRedirectsToIndexHTML578=== RUN TestReadProxyDisabled579=== PAUSE TestReadProxyDisabled580=== RUN TestReadRedirectNar581=== PAUSE TestReadRedirectNar582=== RUN TestReadRedirectKeepsNarinfoProxied583=== PAUSE TestReadRedirectKeepsNarinfoProxied584=== RUN TestReadProxyRangeRequest585=== PAUSE TestReadProxyRangeRequest586=== RUN TestReadRedirectUsesPublicS3URL587=== PAUSE TestReadRedirectUsesPublicS3URL588=== RUN TestPush_OverlappingRootsStoreOneRowPerKey589=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey590=== RUN TestPush_CompleteCommitsEveryRoot591=== PAUSE TestPush_CompleteCommitsEveryRoot592=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected593=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected594=== RUN TestPush_RejectsBadRequests595=== PAUSE TestPush_RejectsBadRequests596=== RUN TestPush_SignsNarinfosOfItsPendingObjects597=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects598=== RUN TestRedundantMultipartUpload599=== PAUSE TestRedundantMultipartUpload600=== RUN TestCompleteMultipartUpload_ErrorButObjectExists601=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists602=== RUN TestCompletedNarNotReofferedAcrossClosures603=== PAUSE TestCompletedNarNotReofferedAcrossClosures604=== RUN TestPresignedUploadRegisteredBeforeCommit605=== PAUSE TestPresignedUploadRegisteredBeforeCommit606=== RUN TestService_Rustfstest607=== PAUSE TestService_Rustfstest608=== RUN TestParseSize609=== PAUSE TestParseSize610=== RUN TestSkippedUploadsHandler611=== PAUSE TestSkippedUploadsHandler612=== RUN TestSystemdListenerNotActivated613--- PASS: TestSystemdListenerNotActivated (0.00s)614=== RUN TestWatchdogBeatsWhenHealthy615--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)616=== RUN TestWatchdogSkipsWhenUnhealthy6172026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6182026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6192026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6202026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:34:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"627--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)628=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle629=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle630=== RUN TestProxyWriteTimeout631=== PAUSE TestProxyWriteTimeout632=== RUN TestIsValidUploadKey633=== PAUSE TestIsValidUploadKey634=== RUN TestUploadHandlersRejectInvalidKeys635=== PAUSE TestUploadHandlersRejectInvalidKeys636=== RUN TestUploadHandlersRejectOversizedBody637=== PAUSE TestUploadHandlersRejectOversizedBody638=== RUN TestService_cleanupPendingClosuresHandler639=== PAUSE TestService_cleanupPendingClosuresHandler640=== RUN TestService_createPendingClosureHandler641=== PAUSE TestService_createPendingClosureHandler642=== RUN TestService_verifyS3Integrity643=== PAUSE TestService_verifyS3Integrity644=== RUN TestCompleteMultipartUnregistered645=== PAUSE TestCompleteMultipartUnregistered646=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT647=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT648=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT649=== CONT TestService_AuthMiddleware650=== CONT TestCompleteMultipartUnregistered651=== CONT TestService_verifyS3Integrity652=== CONT TestService_createPendingClosureHandler653=== CONT TestService_cleanupPendingClosuresHandler654=== CONT TestUploadHandlersRejectOversizedBody655=== CONT TestUploadHandlersRejectInvalidKeys656=== CONT TestIsValidUploadKey657=== CONT TestService_NativeMTLS658=== RUN TestIsValidUploadKey/narinfo659=== CONT TestMetricsInventory660=== CONT TestNARDeduplicationMetadataUploadBug661=== CONT TestCreatePendingClosureRejectsOversizedNAR662=== CONT TestCacheConfigHandlerMaxNarSize663=== CONT TestGenerateLandingPage664=== CONT TestServerTLSConfig665=== CONT TestService_readinessHandler666=== CONT TestProxyWriteTimeout667=== CONT TestService_healthCheckHandler668=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle669=== CONT TestGracefulShutdownDrainsInflight670=== CONT TestSkippedUploadsHandler671=== CONT TestGCTaskStore_Fail672=== CONT TestParseSize673=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info674=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info675=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal676=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal677=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key678=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key679=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key680=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key6812026/09/23 13:34:11 INFO Received uploads request method=POST path=/api/pending_closures682--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)683=== RUN TestProxyWriteTimeout/narinfo684--- PASS: TestParseSize (0.00s)685=== PAUSE TestIsValidUploadKey/narinfo686=== CONT TestService_Rustfstest687=== RUN TestIsValidUploadKey/nar_zst688--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)689=== PAUSE TestIsValidUploadKey/nar_zst690=== RUN TestServerTLSConfig/no_client_CA691=== PAUSE TestServerTLSConfig/no_client_CA692=== RUN TestServerTLSConfig/missing_CA_file693=== RUN TestIsValidUploadKey/nar_xz694--- PASS: TestGenerateLandingPage (0.01s)695=== CONT TestGCTaskStore_PhaseUpdates696--- PASS: TestGCTaskStore_Fail (0.00s)697--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)698=== CONT TestGCTaskStore_GetEmpty699--- PASS: TestGCTaskStore_GetEmpty (0.00s)700=== CONT TestCompletedNarNotReofferedAcrossClosures701=== CONT TestPresignedUploadRegisteredBeforeCommit702=== PAUSE TestIsValidUploadKey/nar_xz7032026/09/23 13:34:11 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000704=== CONT TestGCTaskStore_GetReturnsLatest7052026/09/23 13:34:11 INFO Starting HTTP server address=127.0.0.1:41753706=== CONT TestGCTaskStore_CompletedAllowsNewTask707=== PAUSE TestProxyWriteTimeout/narinfo708=== RUN TestProxyWriteTimeout/1_GiB_nar709=== CONT TestRedundantMultipartUpload710=== CONT TestCompleteMultipartUpload_ErrorButObjectExists711=== PAUSE TestServerTLSConfig/missing_CA_file712=== RUN TestIsValidUploadKey/nar_plain713--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)714=== CONT TestGCTaskStore_ConflictDifferentParams7152026/09/23 13:34:11 INFO Shutdown signal received, draining in-flight requests timeout=10s716=== CONT TestGCTaskStore_DeduplicateSameParams717=== PAUSE TestProxyWriteTimeout/1_GiB_nar718=== RUN TestProxyWriteTimeout/10_GiB_nar719=== RUN TestServerTLSConfig/not_a_PEM_file720=== PAUSE TestServerTLSConfig/not_a_PEM_file721=== PAUSE TestIsValidUploadKey/nar_plain722--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)723=== CONT TestReadProxy404724=== PAUSE TestProxyWriteTimeout/10_GiB_nar725=== CONT TestGCTaskStore_StartNew726=== RUN TestIsValidUploadKey/listing727--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)728--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)729--- PASS: TestGCTaskStore_StartNew (0.00s)730=== RUN TestProxyWriteTimeout/unknown_size731=== CONT TestReadProxyNarStreaming732=== PAUSE TestIsValidUploadKey/listing733=== PAUSE TestProxyWriteTimeout/unknown_size734=== RUN TestIsValidUploadKey/build_log735=== CONT TestGCMetrics736=== PAUSE TestIsValidUploadKey/build_log737=== RUN TestIsValidUploadKey/build_log_home-manager_file738=== PAUSE TestIsValidUploadKey/build_log_home-manager_file739=== RUN TestIsValidUploadKey/build_log_plus_in_name740=== PAUSE TestIsValidUploadKey/build_log_plus_in_name741=== RUN TestIsValidUploadKey/build_log_question_mark742=== PAUSE TestIsValidUploadKey/build_log_question_mark743=== RUN TestIsValidUploadKey/build_log_equals744=== PAUSE TestIsValidUploadKey/build_log_equals745=== RUN TestIsValidUploadKey/realisation746=== PAUSE TestIsValidUploadKey/realisation747=== RUN TestIsValidUploadKey/realisation_plus_in_output748=== PAUSE TestIsValidUploadKey/realisation_plus_in_output749=== RUN TestIsValidUploadKey/nix-cache-info750=== PAUSE TestIsValidUploadKey/nix-cache-info751=== RUN TestIsValidUploadKey/index.html752=== PAUSE TestIsValidUploadKey/index.html753=== RUN TestIsValidUploadKey/narinfo_key,_nar_type754=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type755=== RUN TestIsValidUploadKey/nar_key,_narinfo_type756=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type757=== RUN TestIsValidUploadKey/listing_key,_narinfo_type758=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type759=== RUN TestIsValidUploadKey/traversal760=== PAUSE TestIsValidUploadKey/traversal761=== RUN TestIsValidUploadKey/traversal_nar762=== PAUSE TestIsValidUploadKey/traversal_nar763=== RUN TestIsValidUploadKey/absolute764=== PAUSE TestIsValidUploadKey/absolute765=== RUN TestIsValidUploadKey/empty_key766=== PAUSE TestIsValidUploadKey/empty_key767=== RUN TestIsValidUploadKey/unknown_type768=== PAUSE TestIsValidUploadKey/unknown_type769=== CONT TestReadProxyNarinfoAlreadyDecompressed770--- PASS: TestSkippedUploadsHandler (0.17s)771=== CONT TestGCBugBareHashReferences7722026-09-23 13:34:11.784 UTC [431] ERROR: relation "goose_db_version" does not exist at character 367732026-09-23 13:34:11.784 UTC [431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7742026-09-23 13:34:11.784 UTC [429] ERROR: relation "goose_db_version" does not exist at character 367752026-09-23 13:34:11.784 UTC [429] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7762026-09-23 13:34:11.785 UTC [434] ERROR: relation "goose_db_version" does not exist at character 367772026-09-23 13:34:11.785 UTC [434] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC778=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart779=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart7802026-09-23 13:34:11.867 UTC [445] ERROR: relation "goose_db_version" does not exist at character 367812026-09-23 13:34:11.867 UTC [445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC782=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts7832026-09-23 13:34:11.867 UTC [446] ERROR: relation "goose_db_version" does not exist at character 367842026-09-23 13:34:11.867 UTC [446] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC785=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts7862026-09-23 13:34:11.867 UTC [448] ERROR: relation "goose_db_version" does not exist at character 367872026-09-23 13:34:11.867 UTC [448] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC788=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure789=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure790=== CONT TestReadProxyNarinfo7912026-09-23 13:34:11.875 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367922026-09-23 13:34:11.875 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7932026-09-23 13:34:11.875 UTC [455] ERROR: relation "goose_db_version" does not exist at character 367942026-09-23 13:34:11.875 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026-09-23 13:34:11.876 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367962026-09-23 13:34:11.876 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026-09-23 13:34:11.877 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367982026-09-23 13:34:11.877 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-09-23 13:34:11.877 UTC [459] ERROR: relation "goose_db_version" does not exist at character 368002026-09-23 13:34:11.877 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026-09-23 13:34:11.878 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368022026-09-23 13:34:11.878 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8032026-09-23 13:34:11.878 UTC [457] ERROR: relation "goose_db_version" does not exist at character 368042026-09-23 13:34:11.878 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC805--- PASS: TestGracefulShutdownDrainsInflight (0.12s)806=== CONT TestLeadEndsOnShutdown8072026/09/23 13:34:11 OK 20241026095416_initial_model.sql (118.74ms)8082026/09/23 13:34:11 OK 20241026095416_initial_model.sql (53.38ms)8092026/09/23 13:34:11 OK 20241026095416_initial_model.sql (25.64ms)8102026/09/23 13:34:11 OK 20241026095416_initial_model.sql (24.6ms)8112026/09/23 13:34:11 OK 20241026095416_initial_model.sql (58.17ms)8122026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (4.53ms)8132026/09/23 13:34:11 OK 20241026095416_initial_model.sql (26.41ms)8142026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (3.51ms)8152026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (5.13ms)8162026/09/23 13:34:11 OK 20241026095416_initial_model.sql (27.55ms)8172026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (2.86ms)8182026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (4.29ms)8192026/09/23 13:34:11 OK 20241026095416_initial_model.sql (27.52ms)8202026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (5.58ms)8212026/09/23 13:34:11 OK 20241026095416_initial_model.sql (31.61ms)8222026/09/23 13:34:11 OK 20251218171726_add_pins.sql (8.02ms)8232026/09/23 13:34:11 OK 20241026095416_initial_model.sql (30.12ms)8242026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (4.06ms)8252026/09/23 13:34:11 OK 20251218171726_add_pins.sql (6.33ms)8262026/09/23 13:34:11 OK 20241026095416_initial_model.sql (29.42ms)8272026/09/23 13:34:11 OK 20241026095416_initial_model.sql (30.81ms)8282026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (4.37ms)8292026/09/23 13:34:11 OK 20251218171726_add_pins.sql (6.53ms)8302026/09/23 13:34:11 OK 20241026095416_initial_model.sql (36.14ms)8312026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (4.53ms)8322026-09-23 13:34:11.937 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368332026-09-23 13:34:11.937 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8342026-09-23 13:34:11.938 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368352026-09-23 13:34:11.938 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8362026/09/23 13:34:11 OK 20251218171726_add_pins.sql (8.39ms)8372026/09/23 13:34:11 OK 20251218171726_add_pins.sql (9.59ms)8382026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (5.12ms)8392026/09/23 13:34:11 OK 20251218171726_add_pins.sql (6.28ms)8402026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (5.26ms)8412026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (5.45ms)8422026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (6.49ms)8432026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (8.17ms)8442026/09/23 13:34:11 OK 20251218171726_add_pins.sql (10.2ms)8452026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (5.24ms)8462026/09/23 13:34:11 OK 20251218171726_add_pins.sql (6.34ms)8472026/09/23 13:34:11 OK 20251218171726_add_pins.sql (7.84ms)8482026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (8.09ms)8492026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (6.2ms)8502026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (6.15ms)8512026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (13.65ms)8522026-09-23 13:34:11.955 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368532026-09-23 13:34:11.955 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026-09-23 13:34:11.956 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368552026-09-23 13:34:11.956 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8562026/09/23 13:34:11 OK 20260905000000_add_claims.sql (14.85ms)8572026/09/23 13:34:11 OK 20251218171726_add_pins.sql (14.47ms)8582026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (14.79ms)8592026/09/23 13:34:11 OK 20251218171726_add_pins.sql (15.79ms)8602026/09/23 13:34:11 OK 20260905000000_add_claims.sql (11.93ms)8612026/09/23 13:34:11 OK 20260905000000_add_claims.sql (14.86ms)8622026/09/23 13:34:11 OK 20260905000000_add_claims.sql (11.79ms)8632026/09/23 13:34:11 OK 20251218171726_add_pins.sql (16.01ms)8642026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (13.24ms)8652026/09/23 13:34:11 OK 20251218171726_add_pins.sql (17.78ms)8662026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (13.14ms)8672026/09/23 13:34:11 OK 20260905000000_add_claims.sql (11.74ms)8682026/09/23 13:34:11 OK 20241026095416_initial_model.sql (12.96ms)8692026/09/23 13:34:11 OK 20260905000000_add_claims.sql (6.31ms)8702026/09/23 13:34:11 OK 20241026095416_initial_model.sql (14.75ms)8712026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (4.09ms)8722026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)8732026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (5.52ms)8742026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (5.62ms)8752026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (5.21ms)8762026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (6.37ms)8772026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)8782026/09/23 13:34:11 OK 20260905000000_add_claims.sql (7.27ms)8792026/09/23 13:34:11 OK 20260905000000_add_claims.sql (7.67ms)8802026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (7.68ms)8812026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (3.43ms)8822026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (7.88ms)8832026/09/23 13:34:11 OK 20260905000000_add_claims.sql (7.13ms)8842026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200008852026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (4.71ms)8862026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (8.46ms)8872026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (4.17ms)8882026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (4.27ms)8892026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200008902026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (4.23ms)8912026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200008922026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200008932026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (3.8ms)8942026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200008952026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (9.83ms)8962026/09/23 13:34:11 OK 1_commit_pending_closure.sql (3.2ms)8972026/09/23 13:34:11 OK 20251218171726_add_pins.sql (5.98ms)8982026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (4.42ms)8992026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (4.55ms)9002026/09/23 13:34:11 OK 20251218171726_add_pins.sql (5.34ms)9012026-09-23 13:34:11.969 UTC [469] ERROR: relation "goose_db_version" does not exist at character 369022026-09-23 13:34:11.969 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9032026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (4.13ms)9042026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009052026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (4.86ms)9062026/09/23 13:34:11 OK 2_object_stats_trigger.sql (2.39ms)9072026/09/23 13:34:11 OK 1_commit_pending_closure.sql (4.52ms)9082026/09/23 13:34:11 OK 1_commit_pending_closure.sql (4.96ms)9092026/09/23 13:34:11 OK 20260905000000_add_claims.sql (7.41ms)9102026/09/23 13:34:11 OK 20260905000000_add_claims.sql (6.3ms)9112026/09/23 13:34:11 OK 20260905000000_add_claims.sql (7.31ms)9122026/09/23 13:34:11 OK 1_commit_pending_closure.sql (4.69ms)9132026/09/23 13:34:11 OK 1_commit_pending_closure.sql (4.77ms)9142026/09/23 13:34:11 OK 20260905000000_add_claims.sql (5.67ms)9152026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (4.1ms)9162026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009172026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (4.26ms)9182026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009192026/09/23 13:34:11 OK 1_commit_pending_closure.sql (3.72ms)9202026/09/23 13:34:11 OK 3_commit_push.sql (2.54ms)9212026/09/23 13:34:11 goose: up to current file version: 39222026/09/23 13:34:11 OK 2_object_stats_trigger.sql (2.38ms)9232026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (6.17ms)9242026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (4.74ms)9252026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009262026/09/23 13:34:11 OK 20241026095416_initial_model.sql (12.18ms)9272026/09/23 13:34:11 OK 2_object_stats_trigger.sql (3.25ms)9282026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (6.39ms)9292026/09/23 13:34:11 OK 2_object_stats_trigger.sql (3.61ms)9302026/09/23 13:34:11 OK 2_object_stats_trigger.sql (3.31ms)9312026/09/23 13:34:11 OK 20241026095416_initial_model.sql (11.68ms)9322026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (3.09ms)9332026/09/23 13:34:11 OK 3_commit_push.sql (2.13ms)9342026/09/23 13:34:11 OK 2_object_stats_trigger.sql (3.11ms)9352026/09/23 13:34:11 goose: up to current file version: 39362026/09/23 13:34:11 OK 1_commit_pending_closure.sql (3.18ms)9372026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (4.35ms)9382026/09/23 13:34:11 OK 1_commit_pending_closure.sql (3.22ms)9392026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (5.22ms)9402026/09/23 13:34:11 OK 3_commit_push.sql (1.75ms)9412026/09/23 13:34:11 goose: up to current file version: 39422026/09/23 13:34:11 OK 3_commit_push.sql (1.82ms)9432026/09/23 13:34:11 goose: up to current file version: 39442026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (5.7ms)9452026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)9462026/09/23 13:34:11 OK 1_commit_pending_closure.sql (4.05ms)9472026/09/23 13:34:11 OK 3_commit_push.sql (2.82ms)9482026/09/23 13:34:11 goose: up to current file version: 39492026-09-23 13:34:11.979 UTC [470] ERROR: relation "goose_db_version" does not exist at character 369502026-09-23 13:34:11.979 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9512026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (3ms)9522026/09/23 13:34:11 OK 3_commit_push.sql (3.29ms)9532026/09/23 13:34:11 OK 2_object_stats_trigger.sql (2.96ms)9542026/09/23 13:34:11 goose: up to current file version: 39552026/09/23 13:34:11 OK 20260905000000_add_claims.sql (5.51ms)9562026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (3.62ms)9572026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009582026/09/23 13:34:11 OK 2_object_stats_trigger.sql (3.04ms)9592026/09/23 13:34:11 OK 20260905000000_add_claims.sql (5.3ms)9602026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (4.07ms)9612026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009622026-09-23 13:34:11.982 UTC [471] ERROR: relation "goose_db_version" does not exist at character 369632026-09-23 13:34:11.982 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9642026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (4.29ms)9652026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009662026/09/23 13:34:11 OK 2_object_stats_trigger.sql (3.7ms)9672026/09/23 13:34:11 OK 20251218171726_add_pins.sql (4.46ms)9682026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (5.04ms)9692026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009702026/09/23 13:34:11 OK 3_commit_push.sql (3.39ms)9712026/09/23 13:34:11 goose: up to current file version: 39722026/09/23 13:34:11 OK 3_commit_push.sql (3.02ms)9732026/09/23 13:34:11 goose: up to current file version: 39742026/09/23 13:34:11 OK 3_commit_push.sql (1.95ms)9752026/09/23 13:34:11 goose: up to current file version: 39762026/09/23 13:34:11 OK 1_commit_pending_closure.sql (4.15ms)9772026/09/23 13:34:11 OK 20251218171726_add_pins.sql (5.68ms)9782026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (4.59ms)9792026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (4.15ms)9802026/09/23 13:34:11 OK 1_commit_pending_closure.sql (4.17ms)9812026/09/23 13:34:11 OK 1_commit_pending_closure.sql (3.45ms)9822026-09-23 13:34:11.986 UTC [472] ERROR: relation "goose_db_version" does not exist at character 369832026-09-23 13:34:11.986 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9842026/09/23 13:34:11 OK 1_commit_pending_closure.sql (3.92ms)9852026/09/23 13:34:11 OK 2_object_stats_trigger.sql (3.02ms)9862026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (5.31ms)9872026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (3.23ms)9882026-09-23 13:34:11.989 UTC [473] ERROR: relation "goose_db_version" does not exist at character 369892026-09-23 13:34:11.989 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9902026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009912026/09/23 13:34:11 OK 2_object_stats_trigger.sql (3.11ms)9922026/09/23 13:34:11 OK 2_object_stats_trigger.sql (2.66ms)9932026/09/23 13:34:11 OK 2_object_stats_trigger.sql (2.07ms)9942026/09/23 13:34:11 OK 20260923120000_add_pushes.sql (3.56ms)9952026/09/23 13:34:11 goose: successfully migrated database to version: 202609231200009962026/09/23 13:34:11 OK 20241026095416_initial_model.sql (11.12ms)9972026/09/23 13:34:11 OK 3_commit_push.sql (1.89ms)9982026/09/23 13:34:11 goose: up to current file version: 39992026/09/23 13:34:11 OK 20260628120000_add_object_size_and_stats.sql (4.9ms)10002026/09/23 13:34:11 OK 3_commit_push.sql (2.14ms)10012026/09/23 13:34:11 goose: up to current file version: 310022026/09/23 13:34:11 OK 1_commit_pending_closure.sql (3.56ms)10032026/09/23 13:34:11 OK 3_commit_push.sql (3.4ms)10042026/09/23 13:34:11 goose: up to current file version: 310052026/09/23 13:34:11 OK 1_commit_pending_closure.sql (3.29ms)10062026/09/23 13:34:11 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)10072026/09/23 13:34:11 OK 3_commit_push.sql (3.38ms)10082026/09/23 13:34:11 goose: up to current file version: 310092026/09/23 13:34:11 OK 20260905000000_add_claims.sql (4.49ms)10102026-09-23 13:34:11.993 UTC [474] ERROR: relation "goose_db_version" does not exist at character 3610112026-09-23 13:34:11.993 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10122026/09/23 13:34:11 OK 20260905000000_add_claims.sql (4.11ms)10132026-09-23 13:34:11.995 UTC [475] ERROR: relation "goose_db_version" does not exist at character 3610142026-09-23 13:34:11.995 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10152026/09/23 13:34:11 OK 2_object_stats_trigger.sql (3.1ms)10162026/09/23 13:34:11 OK 2_object_stats_trigger.sql (2.95ms)10172026/09/23 13:34:11 OK 20251218171726_add_pins.sql (3.65ms)10182026/09/23 13:34:11 OK 20241026095416_initial_model.sql (10.28ms)10192026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (3.65ms)10202026/09/23 13:34:11 OK 20260920000000_drop_claims.sql (3.19ms)10212026/09/23 13:34:11 OK 3_commit_push.sql (1.93ms)10222026/09/23 13:34:11 goose: up to current file version: 310232026/09/23 13:34:11 OK 3_commit_push.sql (2.13ms)10242026/09/23 13:34:11 goose: up to current file version: 310252026/09/23 13:34:11 OK 20241026095416_initial_model.sql (9.25ms)10262026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (3.24ms)10272026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000010282026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (3.63ms)10292026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)10302026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (3.91ms)10312026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000010322026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)10332026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.44ms)10342026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.19ms)10352026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures10362026/09/23 13:34:12 OK 1_commit_pending_closure.sql (4.41ms)10372026/09/23 13:34:12 OK 20241026095416_initial_model.sql (9.96ms)10382026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.48ms)10392026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.71ms)10402026/09/23 13:34:12 OK 20251218171726_add_pins.sql (5.76ms)10412026/09/23 13:34:12 OK 20241026095416_initial_model.sql (13.19ms)10422026/09/23 13:34:12 OK 3_commit_push.sql (1.83ms)10432026/09/23 13:34:12 goose: up to current file version: 310442026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.18ms)10452026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)10462026/09/23 13:34:12 OK 3_commit_push.sql (2.27ms)10472026/09/23 13:34:12 goose: up to current file version: 310482026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (3.56ms)10492026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (4.18ms)10502026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)10512026/09/23 13:34:12 OK 20241026095416_initial_model.sql (10.34ms)10522026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (5.73ms)10532026/09/23 13:34:12 OK 20251218171726_add_pins.sql (3.32ms)10542026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.78ms)10552026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000010562026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.09ms)10572026/09/23 13:34:12 OK 20241026095416_initial_model.sql (11.92ms)10582026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (3.24ms)10592026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.75ms)10602026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.28ms)10612026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)10622026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)10632026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.8ms)10642026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.77ms)10652026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.67ms)10662026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)10672026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.03ms)10682026/09/23 13:34:12 OK 20251218171726_add_pins.sql (3.26ms)10692026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (1.76ms)10702026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000010712026/09/23 13:34:12 OK 3_commit_push.sql (1.24ms)10722026/09/23 13:34:12 goose: up to current file version: 310732026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.94ms)10742026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.88ms)10752026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.57ms)10762026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.47ms)10772026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.18ms)10782026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000010792026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)10802026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.7ms)10812026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.15ms)10822026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)10832026/09/23 13:34:12 OK 3_commit_push.sql (657.29µs)10842026/09/23 13:34:12 goose: up to current file version: 310852026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.33ms)10862026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (1.78ms)10872026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000010882026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.32ms)10892026/09/23 13:34:12 OK 20260905000000_add_claims.sql (2.4ms)10902026/09/23 13:34:12 OK 2_object_stats_trigger.sql (787.07µs)10912026/09/23 13:34:12 OK 3_commit_push.sql (823.65µs)10922026/09/23 13:34:12 goose: up to current file version: 310932026/09/23 13:34:12 OK 1_commit_pending_closure.sql (1.76ms)10942026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.08ms)10952026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000010962026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (1.79ms)10972026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.28ms)10982026/09/23 13:34:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10992026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.03ms)11002026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (1.25ms)11012026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000011022026/09/23 13:34:12 OK 3_commit_push.sql (807.15µs)11032026/09/23 13:34:12 goose: up to current file version: 311042026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.64ms)11052026/09/23 13:34:12 INFO Aborted multipart uploads count=011062026/09/23 13:34:12 OK 1_commit_pending_closure.sql (1.6ms)11072026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3ms)11082026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.08ms)11092026/09/23 13:34:12 OK 2_object_stats_trigger.sql (787.09µs)11102026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures11112026/09/23 13:34:12 OK 3_commit_push.sql (532.05µs)11122026/09/23 13:34:12 goose: up to current file version: 311132026/09/23 13:34:12 OK 3_commit_push.sql (961.51µs)11142026/09/23 13:34:12 goose: up to current file version: 311152026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (1.6ms)11162026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000011172026/09/23 13:34:12 OK 1_commit_pending_closure.sql (1.57ms)11182026/09/23 13:34:12 OK 2_object_stats_trigger.sql (673.23µs)11192026/09/23 13:34:12 OK 3_commit_push.sql (555.15µs)11202026/09/23 13:34:12 goose: up to current file version: 311212026/09/23 13:34:12 INFO Received cleanup request method=DELETE path=/api/pending_closures11222026/09/23 13:34:12 INFO Aborted multipart uploads count=111232026/09/23 13:34:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11242026-09-23 13:34:12.045 UTC [455] ERROR: Closure does not exist: id=111252026-09-23 13:34:12.045 UTC [455] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11262026-09-23 13:34:12.045 UTC [455] STATEMENT: -- name: CommitPendingClosure :exec1127 SELECT commit_pending_closure($1::bigint)1128 1129--- PASS: TestService_cleanupPendingClosuresHandler (0.43s)1130=== CONT TestIsValidCachePath1131=== RUN TestIsValidCachePath/narinfo1132=== PAUSE TestIsValidCachePath/narinfo1133=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1134=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1135=== RUN TestIsValidCachePath/nar_zst1136=== PAUSE TestIsValidCachePath/nar_zst1137=== RUN TestIsValidCachePath/nar_xz1138=== PAUSE TestIsValidCachePath/nar_xz1139=== RUN TestIsValidCachePath/nar_bz21140=== PAUSE TestIsValidCachePath/nar_bz21141=== RUN TestIsValidCachePath/nar_uncompressed1142=== PAUSE TestIsValidCachePath/nar_uncompressed1143=== RUN TestIsValidCachePath/ls1144=== PAUSE TestIsValidCachePath/ls1145=== RUN TestIsValidCachePath/log1146=== PAUSE TestIsValidCachePath/log1147=== RUN TestIsValidCachePath/realisation1148=== PAUSE TestIsValidCachePath/realisation1149=== RUN TestIsValidCachePath/nix-cache-info1150=== PAUSE TestIsValidCachePath/nix-cache-info1151=== RUN TestIsValidCachePath/index.html1152=== PAUSE TestIsValidCachePath/index.html1153=== RUN TestIsValidCachePath/traversal_parent1154=== PAUSE TestIsValidCachePath/traversal_parent1155=== RUN TestIsValidCachePath/traversal_in_middle1156=== PAUSE TestIsValidCachePath/traversal_in_middle1157=== RUN TestIsValidCachePath/invalid_char_e1158=== PAUSE TestIsValidCachePath/invalid_char_e1159=== RUN TestIsValidCachePath/invalid_char_u1160=== PAUSE TestIsValidCachePath/invalid_char_u1161=== RUN TestIsValidCachePath/random_path1162=== PAUSE TestIsValidCachePath/random_path1163=== RUN TestIsValidCachePath/empty1164=== PAUSE TestIsValidCachePath/empty1165=== RUN TestIsValidCachePath/leading_slash1166=== PAUSE TestIsValidCachePath/leading_slash1167=== RUN TestIsValidCachePath/wrong_extension1168=== PAUSE TestIsValidCachePath/wrong_extension1169=== RUN TestIsValidCachePath/short_hash1170=== PAUSE TestIsValidCachePath/short_hash1171=== CONT TestProxyHeadersOnlyTrustedOnSocket11722026/09/23 13:34:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11732026/09/23 13:34:12 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1174--- PASS: TestCompleteMultipartUnregistered (0.45s)1175=== CONT TestLeadElectsOneAndHandsOver11762026/09/23 13:34:12 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1177--- PASS: TestService_AuthMiddleware (0.47s)1178=== CONT TestReadProxyInvalidPath1179=== NAME TestNARDeduplicationMetadataUploadBug1180 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3054216619/001/store/6jwq8d4k9d61v8f9qxwa2v101am006bx-file1.txt1181--- PASS: TestService_Rustfstest (0.50s)1182=== CONT TestPush_SignsNarinfosOfItsPendingObjects11832026-09-23 13:34:12.120 UTC [503] ERROR: relation "goose_db_version" does not exist at character 3611842026-09-23 13:34:12.120 UTC [503] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11852026/09/23 13:34:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11862026/09/23 13:34:12 OK 20241026095416_initial_model.sql (12.78ms)11872026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures11882026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)11892026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.51ms)11902026-09-23 13:34:12.154 UTC [524] ERROR: relation "goose_db_version" does not exist at character 3611912026-09-23 13:34:12.154 UTC [524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11922026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (6.16ms)11932026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.95ms)1194--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)1195=== CONT TestParseSingleRange1196=== RUN TestParseSingleRange/none1197=== PAUSE TestParseSingleRange/none1198=== RUN TestParseSingleRange/unknown_unit1199=== PAUSE TestParseSingleRange/unknown_unit1200=== RUN TestParseSingleRange/multi-range_ignored1201=== PAUSE TestParseSingleRange/multi-range_ignored1202=== RUN TestParseSingleRange/malformed_no_dash1203=== PAUSE TestParseSingleRange/malformed_no_dash1204=== RUN TestParseSingleRange/malformed_both_empty1205=== PAUSE TestParseSingleRange/malformed_both_empty1206=== RUN TestParseSingleRange/malformed_end_before_start1207=== PAUSE TestParseSingleRange/malformed_end_before_start1208=== RUN TestParseSingleRange/closed1209=== PAUSE TestParseSingleRange/closed1210=== RUN TestParseSingleRange/open-ended1211=== PAUSE TestParseSingleRange/open-ended1212=== RUN TestParseSingleRange/end_clamped_to_size1213=== PAUSE TestParseSingleRange/end_clamped_to_size1214=== RUN TestParseSingleRange/suffix1215=== PAUSE TestParseSingleRange/suffix1216=== RUN TestParseSingleRange/suffix_exceeds_size1217=== PAUSE TestParseSingleRange/suffix_exceeds_size1218=== RUN TestParseSingleRange/single_byte1219=== PAUSE TestParseSingleRange/single_byte1220=== RUN TestParseSingleRange/start_past_EOF12212026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.3ms)1222=== PAUSE TestParseSingleRange/start_past_EOF1223=== RUN TestParseSingleRange/start_far_past_EOF1224=== PAUSE TestParseSingleRange/start_far_past_EOF1225=== CONT TestPush_RejectsBadRequests12262026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.96ms)12272026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000012282026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures12292026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.89ms)12302026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.88ms)12312026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures12322026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures12332026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures12342026-09-23 13:34:12.171 UTC [543] ERROR: relation "goose_db_version" does not exist at character 3612352026-09-23 13:34:12.171 UTC [543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12362026/09/23 13:34:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12372026/09/23 13:34:12 OK 3_commit_push.sql (2.39ms)12382026/09/23 13:34:12 goose: up to current file version: 312392026/09/23 13:34:12 INFO Uploading 6jwq8d4k9d61v8f9qxwa2v101am006bx-file1.txt (160B)12402026/09/23 13:34:12 OK 20241026095416_initial_model.sql (11.46ms)12412026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)12422026/09/23 13:34:12 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12432026/09/23 13:34:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12442026/09/23 13:34:12 OK 20251218171726_add_pins.sql (5.22ms)12452026/09/23 13:34:12 WARN Failed to register uploaded object key=6jwq8d4k9d61v8f9qxwa2v101am006bx.ls error="server returned 404: 404 page not found\n"12462026/09/23 13:34:12 INFO Signed narinfos id=1 count=112472026/09/23 13:34:12 INFO Uploading 1 narinfos12482026/09/23 13:34:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12492026/09/23 13:34:12 WARN Failed to register uploaded object key=6jwq8d4k9d61v8f9qxwa2v101am006bx.narinfo error="server returned 404: 404 page not found\n"12502026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (5.72ms)12512026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.43ms)12522026/09/23 13:34:12 INFO Completed upload id=112532026/09/23 13:34:12 INFO Upload complete. (66ms)12542026-09-23 13:34:12.193 UTC [545] ERROR: relation "goose_db_version" does not exist at character 3612552026-09-23 13:34:12.193 UTC [545] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12562026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (4.41ms)12572026/09/23 13:34:12 OK 20241026095416_initial_model.sql (15.72ms)1258=== NAME TestNARDeduplicationMetadataUploadBug1259 metadata_upload_test.go:54: Retrieved narinfo from S3:1260 StorePath: /build/TestNARDeduplicationMetadataUploadBug3054216619/001/store/6jwq8d4k9d61v8f9qxwa2v101am006bx-file1.txt1261 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1262 Compression: zstd1263 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1264 NarSize: 1601265 References: 1266 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12672026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.66ms)12682026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000012692026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)1270 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1271 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1272 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12732026/09/23 13:34:12 OK 1_commit_pending_closure.sql (3.01ms)12742026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.82ms)12752026/09/23 13:34:12 OK 20251218171726_add_pins.sql (6.08ms)12762026/09/23 13:34:12 OK 3_commit_push.sql (1.92ms)12772026/09/23 13:34:12 goose: up to current file version: 312782026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (12.88ms)12792026/09/23 13:34:12 OK 20241026095416_initial_model.sql (20ms)12802026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.06ms)12812026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)12822026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.66ms)12832026/09/23 13:34:12 OK 20251218171726_add_pins.sql (3.32ms)12842026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (1.93ms)12852026/09/23 13:34:12 goose: successfully migrated database to version: 202609231200001286--- PASS: TestMetricsInventory (0.61s)1287=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected12882026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)12892026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.33ms)12902026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures12912026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.11ms)12922026/09/23 13:34:12 OK 3_commit_push.sql (1.04ms)12932026/09/23 13:34:12 goose: up to current file version: 312942026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.03ms)12952026-09-23 13:34:12.232 UTC [547] ERROR: relation "goose_db_version" does not exist at character 3612962026-09-23 13:34:12.232 UTC [547] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12972026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.22ms)12982026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (1.81ms)1299=== NAME TestNARDeduplicationMetadataUploadBug13002026/09/23 13:34:12 goose: successfully migrated database to version: 202609231200001301 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3054216619/001/store/4xq0303sbyfqhs7xq5xzvs8ks30r6kfp-file2.txt13022026/09/23 13:34:12 OK 1_commit_pending_closure.sql (1.81ms)13032026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2ms)13042026/09/23 13:34:12 OK 3_commit_push.sql (1.6ms)13052026/09/23 13:34:12 goose: up to current file version: 313062026/09/23 13:34:12 OK 20241026095416_initial_model.sql (11.35ms)13072026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)13082026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.15ms)13092026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)1310--- PASS: TestService_healthCheckHandler (0.64s)1311=== CONT TestPush_CompleteCommitsEveryRoot13122026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.81ms)13132026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.11ms)13142026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.66ms)13152026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000013162026/09/23 13:34:12 OK 1_commit_pending_closure.sql (3.45ms)13172026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.65ms)13182026/09/23 13:34:12 OK 3_commit_push.sql (2.02ms)13192026/09/23 13:34:12 goose: up to current file version: 313202026/09/23 13:34:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13212026/09/23 13:34:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1322--- PASS: TestService_NativeMTLS (0.68s)1323=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13242026-09-23 13:34:12.296 UTC [587] ERROR: relation "goose_db_version" does not exist at character 3613252026-09-23 13:34:12.296 UTC [587] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13262026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures13272026/09/23 13:34:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13282026/09/23 13:34:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13292026/09/23 13:34:12 WARN Failed to register uploaded object key=4xq0303sbyfqhs7xq5xzvs8ks30r6kfp.ls error="server returned 404: 404 page not found\n"13302026/09/23 13:34:12 INFO Signed narinfos id=2 count=113312026/09/23 13:34:12 INFO Uploading 1 narinfos13322026/09/23 13:34:12 OK 20241026095416_initial_model.sql (12.1ms)13332026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.42ms)13342026/09/23 13:34:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13352026/09/23 13:34:12 WARN Failed to register uploaded object key=4xq0303sbyfqhs7xq5xzvs8ks30r6kfp.narinfo error="server returned 404: 404 page not found\n"13362026/09/23 13:34:12 WARN readiness check failed error="closed pool"1337--- PASS: TestService_readinessHandler (0.70s)1338=== CONT TestReadRedirectUsesPublicS3URL13392026/09/23 13:34:12 INFO Completed upload id=213402026/09/23 13:34:12 INFO Upload complete. (56ms)13412026/09/23 13:34:12 OK 20251218171726_add_pins.sql (5.07ms)1342=== NAME TestNARDeduplicationMetadataUploadBug1343 metadata_upload_test.go:76: Retrieved narinfo from S3:1344 StorePath: /build/TestNARDeduplicationMetadataUploadBug3054216619/001/store/4xq0303sbyfqhs7xq5xzvs8ks30r6kfp-file2.txt1345 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1346 Compression: zstd1347 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1348 NarSize: 1601349 References: 1350 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13512026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)1352 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1353 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1354 {"version":1,"root":{"type":"regular","size":44}}13552026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.61ms)1356--- PASS: TestNARDeduplicationMetadataUploadBug (0.72s)1357=== CONT TestReadProxyRangeRequest13582026-09-23 13:34:12.333 UTC [609] ERROR: relation "goose_db_version" does not exist at character 3613592026-09-23 13:34:12.333 UTC [609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13602026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.17ms)13612026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.68ms)13622026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000013632026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.98ms)13642026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.86ms)13652026/09/23 13:34:12 OK 3_commit_push.sql (1.86ms)13662026/09/23 13:34:12 goose: up to current file version: 313672026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures13682026/09/23 13:34:12 OK 20241026095416_initial_model.sql (11.58ms)13692026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (9.64ms)13702026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.41ms)13712026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)13722026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.39ms)13732026-09-23 13:34:12.375 UTC [612] ERROR: relation "goose_db_version" does not exist at character 3613742026-09-23 13:34:12.375 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13752026/09/23 13:34:12 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13762026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures13772026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (4.21ms)1378--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.60s)1379=== CONT TestReadRedirectKeepsNarinfoProxied13802026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.83ms)13812026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000013822026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.88ms)1383--- PASS: TestReadProxy404 (0.61s)1384=== CONT TestReadRedirectNar13852026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.27ms)13862026/09/23 13:34:12 OK 3_commit_push.sql (2.02ms)13872026/09/23 13:34:12 goose: up to current file version: 313882026/09/23 13:34:12 OK 20241026095416_initial_model.sql (10.98ms)13892026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)13902026-09-23 13:34:12.397 UTC [616] ERROR: relation "goose_db_version" does not exist at character 3613912026-09-23 13:34:12.397 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13922026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.35ms)13932026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)13942026-09-23 13:34:12.406 UTC [618] ERROR: relation "goose_db_version" does not exist at character 3613952026-09-23 13:34:12.406 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13962026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.97ms)13972026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (4.04ms)13982026/09/23 13:34:12 OK 20241026095416_initial_model.sql (12.34ms)13992026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (3.78ms)14002026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000014012026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)14022026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures14032026/09/23 13:34:12 OK 1_commit_pending_closure.sql (3.27ms)14042026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.27ms)14052026/09/23 13:34:12 OK 20251218171726_add_pins.sql (5.06ms)14062026/09/23 13:34:12 OK 20241026095416_initial_model.sql (12.1ms)14072026/09/23 13:34:12 OK 3_commit_push.sql (1.7ms)14082026/09/23 13:34:12 goose: up to current file version: 314092026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)14102026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)14112026/09/23 13:34:12 OK 20251218171726_add_pins.sql (3.98ms)14122026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.72ms)14132026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)14142026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.33ms)14152026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures14162026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (3.44ms)14172026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000014182026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.73ms)14192026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.8ms)14202026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.77ms)14212026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.34ms)14222026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures14232026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (12.27ms)14242026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000014252026/09/23 13:34:12 OK 3_commit_push.sql (11.91ms)14262026/09/23 13:34:12 goose: up to current file version: 314272026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.13ms)14282026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.01ms)14292026/09/23 13:34:12 OK 3_commit_push.sql (1.03ms)14302026/09/23 13:34:12 goose: up to current file version: 314312026-09-23 13:34:12.468 UTC [619] ERROR: relation "goose_db_version" does not exist at character 3614322026-09-23 13:34:12.468 UTC [619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14332026-09-23 13:34:12.469 UTC [620] ERROR: relation "goose_db_version" does not exist at character 3614342026-09-23 13:34:12.469 UTC [620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14352026/09/23 13:34:12 OK 20241026095416_initial_model.sql (10.64ms)14362026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)14372026/09/23 13:34:12 OK 20241026095416_initial_model.sql (10.01ms)14382026/09/23 13:34:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14392026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)14402026/09/23 13:34:12 OK 20251218171726_add_pins.sql (2.87ms)1441--- PASS: TestReadProxyNarStreaming (0.72s)1442=== CONT TestCreatePin_ReservedPins14432026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.07ms)14442026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)14452026/09/23 13:34:12 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTg0YjkyMmItY2E4Ny00MTU2LWJhNjctMzM3ZTNmOWM1MzZhLmE4OWQxNDI2LTRjYTctNGY5YS04ZjJjLWJhMWZlNmVkZTliMXgxNzkwMTcwNDUyNDYzNTA2NzMz14462026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)14472026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.94ms)14482026/09/23 13:34:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTg0YjkyMmItY2E4Ny00MTU2LWJhNjctMzM3ZTNmOWM1MzZhLmE4OWQxNDI2LTRjYTctNGY5YS04ZjJjLWJhMWZlNmVkZTliMXgxNzkwMTcwNDUyNDYzNTA2NzMz parts=11449--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.72s)1450=== CONT TestReadProxyDisabled14512026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.18ms)14522026/09/23 13:34:12 OK 20260905000000_add_claims.sql (2.56ms)14532026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.06ms)14542026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.3ms)14552026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000014562026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (1.56ms)14572026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000014582026/09/23 13:34:12 OK 1_commit_pending_closure.sql (1.93ms)14592026/09/23 13:34:12 OK 1_commit_pending_closure.sql (1.68ms)14602026/09/23 13:34:12 OK 2_object_stats_trigger.sql (877.63µs)14612026/09/23 13:34:12 OK 2_object_stats_trigger.sql (726.49µs)14622026/09/23 13:34:12 OK 3_commit_push.sql (751.87µs)14632026/09/23 13:34:12 goose: up to current file version: 314642026/09/23 13:34:12 OK 3_commit_push.sql (799.71µs)14652026/09/23 13:34:12 goose: up to current file version: 31466--- PASS: TestReadProxyNarinfo (0.65s)1467=== CONT TestResurrectedObjectNotDeleted14682026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures14692026-09-23 13:34:12.568 UTC [625] ERROR: relation "goose_db_version" does not exist at character 3614702026-09-23 13:34:12.568 UTC [625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14712026/09/23 13:34:12 OK 20241026095416_initial_model.sql (9.76ms)14722026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)14732026/09/23 13:34:12 OK 20251218171726_add_pins.sql (3.24ms)14742026-09-23 13:34:12.591 UTC [626] ERROR: relation "goose_db_version" does not exist at character 3614752026-09-23 13:34:12.591 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14762026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)14772026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.64ms)14782026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.68ms)14792026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.55ms)14802026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000014812026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.54ms)1482--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.83s)1483=== CONT TestReadProxyRootRedirectsToIndexHTML14842026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.73ms)14852026/09/23 13:34:12 OK 20241026095416_initial_model.sql (9.96ms)14862026/09/23 13:34:12 OK 3_commit_push.sql (971.59µs)14872026/09/23 13:34:12 goose: up to current file version: 314882026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)14892026/09/23 13:34:12 OK 20251218171726_add_pins.sql (3.53ms)14902026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (2.84ms)14912026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.56ms)14922026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.02ms)14932026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (3.18ms)14942026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000014952026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.78ms)14962026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.15ms)14972026/09/23 13:34:12 OK 3_commit_push.sql (1.95ms)14982026/09/23 13:34:12 goose: up to current file version: 314992026/09/23 13:34:12 INFO Aborted multipart uploads count=015002026/09/23 13:34:12 WARN Force mode enabled - objects will be deleted immediately without grace period15012026/09/23 13:34:12 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=015022026/09/23 13:34:12 INFO Vacuumed table table=pending_closures15032026/09/23 13:34:12 INFO Vacuumed table table=pending_objects15042026/09/23 13:34:12 INFO Vacuumed table table=multipart_uploads15052026/09/23 13:34:12 INFO Vacuumed table table=closures15062026/09/23 13:34:12 INFO Vacuumed table table=objects1507--- PASS: TestGCMetrics (0.87s)1508=== CONT TestOrphanedObjectsGCStressTest15092026/09/23 13:34:12 INFO lead: acquired remote=192.0.2.1:123415102026/09/23 13:34:12 INFO lead: released remote=192.0.2.1:12341511--- PASS: TestLeadEndsOnShutdown (0.76s)1512=== CONT TestReadProxyConditionalGet15132026-09-23 13:34:12.674 UTC [634] ERROR: relation "goose_db_version" does not exist at character 3615142026-09-23 13:34:12.674 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15152026/09/23 13:34:12 INFO Starting HTTP server address=127.0.0.1:4655115162026/09/23 13:34:12 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket25311308/001/proxy.sock15172026/09/23 13:34:12 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15182026/09/23 13:34:12 INFO Shutdown signal received, draining in-flight requests timeout=10s1519--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.64s)1520=== CONT TestOrphanedObjectsGC15212026/09/23 13:34:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15222026/09/23 13:34:12 OK 20241026095416_initial_model.sql (12.03ms)15232026/09/23 13:34:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41183/oidc15242026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.24ms)15252026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.07ms)15262026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (5.38ms)15272026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.99ms)15282026/09/23 13:34:12 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTg0YjkyMmItY2E4Ny00MTU2LWJhNjctMzM3ZTNmOWM1MzZhLmZjZjM0NDI1LWU4MzctNDZjYi05YmZmLWYzZTI2YzI3Zjg3OHgxNzkwMTcwNDUyMTc4NDM2Mzcx parts=1015292026/09/23 13:34:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15302026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.18ms)15312026/09/23 13:34:12 INFO lead: acquired remote=192.0.2.1:123415322026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (3.2ms)15332026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000015342026/09/23 13:34:12 INFO Completed upload id=115352026/09/23 13:34:12 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015362026/09/23 13:34:12 OK 1_commit_pending_closure.sql (3.35ms)15372026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures15382026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.82ms)15392026/09/23 13:34:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures15402026/09/23 13:34:12 OK 3_commit_push.sql (1.32ms)15412026/09/23 13:34:12 goose: up to current file version: 315422026-09-23 13:34:12.729 UTC [656] ERROR: relation "goose_db_version" does not exist at character 3615432026-09-23 13:34:12.729 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15442026-09-23 13:34:12.734 UTC [657] ERROR: relation "goose_db_version" does not exist at character 3615452026-09-23 13:34:12.734 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15462026/09/23 13:34:12 INFO Aborted multipart uploads count=015472026/09/23 13:34:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15482026/09/23 13:34:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=01549--- PASS: TestReadProxyInvalidPath (0.66s)1550=== CONT TestReadProxyHead15512026/09/23 13:34:12 OK 20241026095416_initial_model.sql (14.21ms)15522026/09/23 13:34:12 INFO Vacuumed table table=pending_closures15532026/09/23 13:34:12 OK 20241026095416_initial_model.sql (12.33ms)15542026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)15552026/09/23 13:34:12 INFO Vacuumed table table=pending_objects15562026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)15572026/09/23 13:34:12 INFO Vacuumed table table=multipart_uploads15582026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.53ms)15592026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.76ms)15602026/09/23 13:34:12 INFO Vacuumed table table=closures15612026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.97ms)15622026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)15632026/09/23 13:34:12 INFO Vacuumed table table=objects15642026/09/23 13:34:12 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTg0YjkyMmItY2E4Ny00MTU2LWJhNjctMzM3ZTNmOWM1MzZhLmRmZjVlZGVjLWFjMjItNGViNS04ZGJmLTUwNzA1ZTFiZTExMHgxNzkwMTcwNDUyMjM4MjE2OTQ0 parts=1015652026/09/23 13:34:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15662026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.22ms)15672026-09-23 13:34:12.769 UTC [661] ERROR: relation "goose_db_version" does not exist at character 3615682026-09-23 13:34:12.769 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15692026/09/23 13:34:12 OK 20260905000000_add_claims.sql (5.57ms)15702026/09/23 13:34:12 INFO Completed upload id=115712026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures15722026/09/23 13:34:12 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001573--- PASS: TestService_createPendingClosureHandler (1.17s)1574=== CONT TestObjectStatsTrigger15752026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (13.4ms)15762026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (12.23ms)15772026/09/23 13:34:12 INFO Received uploads request method=POST path=/api/pending_closures15782026/09/23 13:34:12 INFO Received push request method=POST path=/api/pushes15792026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (3.27ms)15802026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000015812026/09/23 13:34:12 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15822026/09/23 13:34:12 WARN Found objects in DB but missing from S3, will re-upload count=115832026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (4.67ms)15842026/09/23 13:34:12 goose: successfully migrated database to version: 202609231200001585--- PASS: TestService_verifyS3Integrity (1.17s)1586=== CONT TestMultipartCleanup15872026/09/23 13:34:12 OK 1_commit_pending_closure.sql (4.35ms)15882026/09/23 13:34:12 OK 1_commit_pending_closure.sql (3.85ms)15892026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.6ms)15902026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.1ms)15912026/09/23 13:34:12 OK 3_commit_push.sql (2.1ms)15922026/09/23 13:34:12 goose: up to current file version: 315932026/09/23 13:34:12 OK 20241026095416_initial_model.sql (10.83ms)15942026/09/23 13:34:12 OK 3_commit_push.sql (2.92ms)15952026/09/23 13:34:12 goose: up to current file version: 315962026-09-23 13:34:12.795 UTC [664] ERROR: relation "goose_db_version" does not exist at character 3615972026-09-23 13:34:12.795 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15982026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (3.74ms)15992026/09/23 13:34:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16002026/09/23 13:34:12 INFO Signed narinfos id=1 count=11601--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.68s)1602=== CONT TestClientMultipleUploads1603--- PASS: TestGCBugBareHashReferences (1.02s)1604=== CONT TestClientErrorHandling1605=== RUN TestClientErrorHandling/InvalidStorePath1606=== PAUSE TestClientErrorHandling/InvalidStorePath1607=== RUN TestClientErrorHandling/InvalidAuthToken1608=== PAUSE TestClientErrorHandling/InvalidAuthToken1609=== RUN TestClientErrorHandling/ServerNotAvailable1610=== PAUSE TestClientErrorHandling/ServerNotAvailable1611=== CONT TestPinProtectsFromGC16122026/09/23 13:34:12 OK 20251218171726_add_pins.sql (5.34ms)16132026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (6.14ms)16142026/09/23 13:34:12 OK 20241026095416_initial_model.sql (12.19ms)16152026/09/23 13:34:12 OK 20260905000000_add_claims.sql (5.7ms)1616=== RUN TestPush_RejectsBadRequests/no_roots1617=== PAUSE TestPush_RejectsBadRequests/no_roots1618=== RUN TestPush_RejectsBadRequests/no_objects16192026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (3.87ms)1620=== PAUSE TestPush_RejectsBadRequests/no_objects1621=== RUN TestPush_RejectsBadRequests/bad_root1622=== PAUSE TestPush_RejectsBadRequests/bad_root1623=== RUN TestPush_RejectsBadRequests/root_not_in_objects1624=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1625=== CONT TestResolveDBConnectionString1626=== RUN TestResolveDBConnectionString/flag_wins1627=== PAUSE TestResolveDBConnectionString/flag_wins1628=== RUN TestResolveDBConnectionString/file_when_flag_empty1629=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1630=== RUN TestResolveDBConnectionString/missing_file_is_an_error1631=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1632=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1633=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1634=== RUN TestResolveDBConnectionString/nothing_configured1635=== PAUSE TestResolveDBConnectionString/nothing_configured1636=== CONT TestClientIntegration16372026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (5.23ms)16382026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.93ms)16392026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (5.1ms)16402026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000016412026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (6.49ms)16422026/09/23 13:34:12 OK 1_commit_pending_closure.sql (4.37ms)16432026/09/23 13:34:12 OK 2_object_stats_trigger.sql (3.55ms)16442026/09/23 13:34:12 OK 20260905000000_add_claims.sql (5.12ms)16452026/09/23 13:34:12 OK 3_commit_push.sql (4.02ms)16462026/09/23 13:34:12 goose: up to current file version: 316472026-09-23 13:34:12.840 UTC [673] ERROR: relation "goose_db_version" does not exist at character 3616482026-09-23 13:34:12.840 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16492026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (6.93ms)16502026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (5.69ms)16512026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000016522026/09/23 13:34:12 OK 1_commit_pending_closure.sql (4.21ms)16532026/09/23 13:34:12 INFO Received push request method=POST path=/api/pushes16542026/09/23 13:34:12 OK 2_object_stats_trigger.sql (10.68ms)16552026/09/23 13:34:12 INFO lead: released remote=192.0.2.1:123416562026/09/23 13:34:12 OK 3_commit_push.sql (9.24ms)16572026/09/23 13:34:12 goose: up to current file version: 316582026/09/23 13:34:12 OK 20241026095416_initial_model.sql (21.19ms)16592026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.88ms)16602026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.72ms)16612026-09-23 13:34:12.882 UTC [674] ERROR: relation "goose_db_version" does not exist at character 3616622026-09-23 13:34:12.882 UTC [674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16632026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (5.88ms)16642026-09-23 13:34:12.887 UTC [675] ERROR: relation "goose_db_version" does not exist at character 3616652026-09-23 13:34:12.887 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16662026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.69ms)16672026/09/23 13:34:12 INFO Received complete push request method=POST path=/api/pushes/1/complete16682026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.94ms)16692026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.89ms)16702026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000016712026-09-23 13:34:12.899 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3616722026-09-23 13:34:12.899 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16732026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.65ms)16742026/09/23 13:34:12 INFO Received push request method=POST path=/api/pushes16752026/09/23 13:34:12 OK 20241026095416_initial_model.sql (11.36ms)16762026/09/23 13:34:12 INFO Received push request method=POST path=/api/pushes16772026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.13ms)16782026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)16792026/09/23 13:34:12 OK 20241026095416_initial_model.sql (11.02ms)16802026/09/23 13:34:12 OK 3_commit_push.sql (1.69ms)16812026/09/23 13:34:12 goose: up to current file version: 316822026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)16832026/09/23 13:34:12 OK 20251218171726_add_pins.sql (3.61ms)16842026/09/23 13:34:12 OK 20251218171726_add_pins.sql (3.11ms)16852026-09-23 13:34:12.910 UTC [678] ERROR: relation "goose_db_version" does not exist at character 3616862026-09-23 13:34:12.910 UTC [678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16872026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)16882026/09/23 13:34:12 INFO Received complete push request method=POST path=/api/pushes/2/complete16892026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (3.12ms)16902026-09-23 13:34:12.913 UTC [676] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo16912026-09-23 13:34:12.913 UTC [676] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE16922026-09-23 13:34:12.913 UTC [676] STATEMENT: -- name: CommitPush :exec1693 SELECT commit_push($1::bigint)1694 1695--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (0.69s)1696=== CONT TestCacheStatsHandler16972026-09-23 13:34:12.915 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3616982026-09-23 13:34:12.915 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16992026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.36ms)17002026/09/23 13:34:12 OK 20241026095416_initial_model.sql (11.06ms)17012026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.14ms)17022026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)17032026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.83ms)17042026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.15ms)17052026/09/23 13:34:12 INFO lead: acquired remote=192.0.2.1:123417062026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.45ms)17072026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000017082026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.33ms)17092026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000017102026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.27ms)17112026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.69ms)17122026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.52ms)17132026/09/23 13:34:12 INFO Received complete push request method=POST path=/api/pushes/1/complete17142026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.81ms)17152026/09/23 13:34:12 INFO lead: released remote=192.0.2.1:12341716--- PASS: TestLeadElectsOneAndHandsOver (0.86s)1717=== CONT TestCacheConfigHandler1718=== RUN TestCacheConfigHandler/full_config,_no_issuer1719=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1720=== RUN TestCacheConfigHandler/no_cache_url_configured1721=== PAUSE TestCacheConfigHandler/no_cache_url_configured1722=== RUN TestCacheConfigHandler/no_signing_keys1723=== PAUSE TestCacheConfigHandler/no_signing_keys1724=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1725=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1726=== CONT TestService_AuthMiddleware_OIDC17272026/09/23 13:34:12 OK 2_object_stats_trigger.sql (3.19ms)17282026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)17292026/09/23 13:34:12 OK 3_commit_push.sql (2.26ms)17302026/09/23 13:34:12 goose: up to current file version: 317312026/09/23 13:34:12 OK 20241026095416_initial_model.sql (12.36ms)17322026/09/23 13:34:12 OK 3_commit_push.sql (1.76ms)17332026/09/23 13:34:12 goose: up to current file version: 317342026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.08ms)17352026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (4.01ms)17362026/09/23 13:34:12 OK 20241026095416_initial_model.sql (13.38ms)17372026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.19ms)1738--- PASS: TestPush_CompleteCommitsEveryRoot (0.68s)17392026/09/23 13:34:12 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)1740=== CONT TestClientCADerivations17412026/09/23 13:34:12 INFO Received push request method=POST path=/api/pushes17422026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.41ms)17432026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (4.13ms)17442026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000017452026/09/23 13:34:12 OK 20251218171726_add_pins.sql (4.8ms)17462026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.7ms)17472026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (5.73ms)17482026/09/23 13:34:12 OK 2_object_stats_trigger.sql (2.57ms)17492026/09/23 13:34:12 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)17502026/09/23 13:34:12 OK 3_commit_push.sql (995.97µs)17512026/09/23 13:34:12 goose: up to current file version: 317522026/09/23 13:34:12 OK 20260905000000_add_claims.sql (4.53ms)17532026/09/23 13:34:12 OK 20260905000000_add_claims.sql (3.96ms)17542026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (3.64ms)17552026/09/23 13:34:12 OK 20260920000000_drop_claims.sql (2.84ms)17562026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (2.78ms)17572026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000017582026/09/23 13:34:12 OK 20260923120000_add_pushes.sql (3.53ms)17592026/09/23 13:34:12 goose: successfully migrated database to version: 2026092312000017602026/09/23 13:34:12 OK 1_commit_pending_closure.sql (3.27ms)17612026/09/23 13:34:12 OK 1_commit_pending_closure.sql (2.67ms)17622026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.91ms)17632026/09/23 13:34:12 OK 2_object_stats_trigger.sql (1.96ms)1764--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.67s)1765=== CONT TestService_ReadAuthMiddleware17662026/09/23 13:34:12 OK 3_commit_push.sql (1.98ms)17672026/09/23 13:34:12 goose: up to current file version: 317682026/09/23 13:34:12 OK 3_commit_push.sql (2.22ms)17692026/09/23 13:34:12 goose: up to current file version: 317702026-09-23 13:34:12.992 UTC [691] ERROR: relation "goose_db_version" does not exist at character 3617712026-09-23 13:34:12.992 UTC [691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1772--- PASS: TestReadRedirectUsesPublicS3URL (0.68s)1773=== CONT TestService_ReadScope_PublicByDefault17742026/09/23 13:34:13 OK 20241026095416_initial_model.sql (11.17ms)17752026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)17762026-09-23 13:34:13.016 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3617772026-09-23 13:34:13.016 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1778--- PASS: TestReadProxyRangeRequest (0.68s)1779=== CONT TestClientSharedPathCommittedMidPush17802026/09/23 13:34:13 OK 20251218171726_add_pins.sql (4.27ms)17812026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (4.42ms)17822026/09/23 13:34:13 OK 20260905000000_add_claims.sql (5.31ms)17832026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (3.36ms)17842026/09/23 13:34:13 OK 20241026095416_initial_model.sql (11.47ms)17852026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (3.13ms)17862026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000017872026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)17882026/09/23 13:34:13 OK 1_commit_pending_closure.sql (4.18ms)17892026/09/23 13:34:13 OK 20251218171726_add_pins.sql (3.95ms)17902026/09/23 13:34:13 OK 2_object_stats_trigger.sql (2.12ms)17912026/09/23 13:34:13 OK 3_commit_push.sql (1.91ms)17922026/09/23 13:34:13 goose: up to current file version: 31793--- PASS: TestReadRedirectKeepsNarinfoProxied (0.67s)1794=== CONT TestService_RequireScope_OIDC17952026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (4.56ms)17962026-09-23 13:34:13.049 UTC [697] ERROR: relation "goose_db_version" does not exist at character 3617972026-09-23 13:34:13.049 UTC [697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17982026/09/23 13:34:13 OK 20260905000000_add_claims.sql (3.95ms)17992026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (2.97ms)18002026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (3.5ms)18012026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000018022026/09/23 13:34:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46845/oidc18032026/09/23 13:34:13 OK 1_commit_pending_closure.sql (2.88ms)18042026/09/23 13:34:13 OK 2_object_stats_trigger.sql (1.81ms)18052026/09/23 13:34:13 OK 3_commit_push.sql (1.78ms)18062026/09/23 13:34:13 goose: up to current file version: 318072026/09/23 13:34:13 OK 20241026095416_initial_model.sql (11.4ms)18082026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)18092026/09/23 13:34:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18102026-09-23 13:34:13.076 UTC [700] ERROR: relation "goose_db_version" does not exist at character 3618112026-09-23 13:34:13.076 UTC [700] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1812--- PASS: TestReadRedirectNar (0.69s)1813=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18142026/09/23 13:34:13 OK 20251218171726_add_pins.sql (11.03ms)18152026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)18162026/09/23 13:34:13 OK 20260905000000_add_claims.sql (3.65ms)18172026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (3.15ms)18182026-09-23 13:34:13.094 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3618192026-09-23 13:34:13.094 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18202026/09/23 13:34:13 OK 20241026095416_initial_model.sql (10.92ms)18212026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (2.86ms)18222026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000018232026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)18242026/09/23 13:34:13 OK 1_commit_pending_closure.sql (2.88ms)18252026/09/23 13:34:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTg0YjkyMmItY2E4Ny00MTU2LWJhNjctMzM3ZTNmOWM1MzZhLmU5NjhkYzlkLTQwYmQtNGNhMy05MmRiLTRkZWE0MjQxNzFlOHgxNzkwMTcwNDUyNDMyODU2NTM5 parts=1218262026/09/23 13:34:13 OK 2_object_stats_trigger.sql (1.28ms)18272026/09/23 13:34:13 OK 20251218171726_add_pins.sql (3.88ms)1828--- PASS: TestRedundantMultipartUpload (1.33s)1829=== CONT TestService_AuthMiddleware_MTLSProxyHeader1830--- PASS: TestReadProxyDisabled (0.60s)1831=== CONT TestClientWithDependencies18322026/09/23 13:34:13 OK 3_commit_push.sql (2.5ms)18332026/09/23 13:34:13 goose: up to current file version: 318342026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (4.7ms)18352026/09/23 13:34:13 OK 20260905000000_add_claims.sql (4.3ms)18362026/09/23 13:34:13 OK 20241026095416_initial_model.sql (11.39ms)18372026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (2.71ms)18382026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)18392026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (2.81ms)18402026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000018412026/09/23 13:34:13 OK 20251218171726_add_pins.sql (3.64ms)18422026/09/23 13:34:13 OK 1_commit_pending_closure.sql (3.04ms)18432026/09/23 13:34:13 OK 2_object_stats_trigger.sql (2.12ms)18442026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (5ms)18452026/09/23 13:34:13 OK 3_commit_push.sql (1.79ms)18462026/09/23 13:34:13 goose: up to current file version: 318472026/09/23 13:34:13 OK 20260905000000_add_claims.sql (4.47ms)18482026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (3.67ms)18492026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (3.04ms)18502026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000018512026/09/23 13:34:13 OK 1_commit_pending_closure.sql (3.51ms)18522026-09-23 13:34:13.140 UTC [708] ERROR: relation "goose_db_version" does not exist at character 3618532026-09-23 13:34:13.140 UTC [708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18542026/09/23 13:34:13 OK 2_object_stats_trigger.sql (2.83ms)18552026/09/23 13:34:13 OK 3_commit_push.sql (2ms)18562026/09/23 13:34:13 goose: up to current file version: 318572026/09/23 13:34:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18582026-09-23 13:34:13.157 UTC [709] ERROR: relation "goose_db_version" does not exist at character 3618592026-09-23 13:34:13.157 UTC [709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18602026/09/23 13:34:13 OK 20241026095416_initial_model.sql (11.87ms)18612026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (8.92ms)18622026/09/23 13:34:13 OK 20251218171726_add_pins.sql (3.66ms)1863--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.57s)1864=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18652026/09/23 13:34:13 INFO Received uploads request method=POST path=/1866=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18672026/09/23 13:34:13 INFO Received request for more parts method=POST path=/1868=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18692026/09/23 13:34:13 INFO Received complete multipart upload request method=POST path=/1870=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18712026/09/23 13:34:13 INFO Received uploads request method=POST path=/1872--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1873 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1874 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1875 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1876 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1877=== CONT TestServerTLSConfig/no_client_CA1878=== CONT TestServerTLSConfig/not_a_PEM_file1879=== CONT TestServerTLSConfig/missing_CA_file18802026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (2.97ms)1881--- PASS: TestServerTLSConfig (0.16s)1882 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1883 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1884 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1885=== CONT TestProxyWriteTimeout/narinfo1886=== CONT TestProxyWriteTimeout/unknown_size1887=== CONT TestProxyWriteTimeout/10_GiB_nar1888=== CONT TestProxyWriteTimeout/1_GiB_nar1889--- PASS: TestProxyWriteTimeout (0.16s)1890 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1891 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1892 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1893 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1894=== CONT TestIsValidUploadKey/narinfo1895=== CONT TestIsValidUploadKey/unknown_type1896=== CONT TestIsValidUploadKey/empty_key1897=== CONT TestIsValidUploadKey/absolute1898=== CONT TestIsValidUploadKey/traversal_nar1899=== CONT TestIsValidUploadKey/traversal1900=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1901=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1902=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1903=== CONT TestIsValidUploadKey/index.html1904=== CONT TestIsValidUploadKey/build_log_home-manager_file1905=== CONT TestIsValidUploadKey/build_log1906=== CONT TestIsValidUploadKey/listing1907=== CONT TestIsValidUploadKey/nar_plain1908=== CONT TestIsValidUploadKey/nar_xz1909=== CONT TestIsValidUploadKey/nar_zst1910=== CONT TestIsValidUploadKey/build_log_plus_in_name1911=== CONT TestIsValidUploadKey/realisation1912=== CONT TestIsValidUploadKey/nix-cache-info1913=== CONT TestIsValidUploadKey/build_log_equals1914=== CONT TestIsValidUploadKey/realisation_plus_in_output1915=== CONT TestIsValidUploadKey/build_log_question_mark1916=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19172026/09/23 13:34:13 INFO Received complete multipart upload request method=POST path=/1918--- PASS: TestIsValidUploadKey (0.16s)1919 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1920 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1921 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1922 --- PASS: TestIsValidUploadKey/absolute (0.00s)1923 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1924 --- PASS: TestIsValidUploadKey/traversal (0.00s)1925 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1926 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1927 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1928 --- PASS: TestIsValidUploadKey/index.html (0.00s)1929 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1930 --- PASS: TestIsValidUploadKey/build_log (0.00s)1931 --- PASS: TestIsValidUploadKey/listing (0.00s)1932 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1933 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1934 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1935 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1936 --- PASS: TestIsValidUploadKey/realisation (0.00s)1937 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1938 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1939 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1940 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)19412026/09/23 13:34:13 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTg0YjkyMmItY2E4Ny00MTU2LWJhNjctMzM3ZTNmOWM1MzZhLjhiMTQ4NmIyLWYyZTgtNDAxYS1iNWM1LTUxZWM5OTBjZDgyZngxNzkwMTcwNDUyNTUwMTc3OTY1 parts=1219422026/09/23 13:34:13 OK 20260905000000_add_claims.sql (3.31ms)19432026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures19442026/09/23 13:34:13 OK 20241026095416_initial_model.sql (10.12ms)19452026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (2.42ms)1946--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.41s)1947=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19482026/09/23 13:34:13 INFO Received request for more parts method=POST path=/19492026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)19502026/09/23 13:34:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39771/oidc19512026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (1.91ms)19522026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000019532026-09-23 13:34:13.185 UTC [710] ERROR: relation "goose_db_version" does not exist at character 3619542026-09-23 13:34:13.185 UTC [710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19552026/09/23 13:34:13 OK 20251218171726_add_pins.sql (3.54ms)19562026/09/23 13:34:13 OK 1_commit_pending_closure.sql (2.89ms)19572026-09-23 13:34:13.186 UTC [711] ERROR: relation "goose_db_version" does not exist at character 3619582026-09-23 13:34:13.186 UTC [711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19592026/09/23 13:34:13 OK 2_object_stats_trigger.sql (2.08ms)19602026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)19612026/09/23 13:34:13 OK 3_commit_push.sql (1.99ms)19622026/09/23 13:34:13 goose: up to current file version: 31963--- PASS: TestResurrectedObjectNotDeleted (0.67s)1964=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19652026/09/23 13:34:13 INFO Received uploads request method=POST path=/19662026/09/23 13:34:13 OK 20260905000000_add_claims.sql (3.92ms)19672026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (3.11ms)19682026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (3.1ms)19692026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000019702026/09/23 13:34:13 OK 20241026095416_initial_model.sql (11.22ms)19712026/09/23 13:34:13 OK 20241026095416_initial_model.sql (12.28ms)19722026/09/23 13:34:13 OK 1_commit_pending_closure.sql (4.15ms)19732026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)19742026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)19752026/09/23 13:34:13 OK 2_object_stats_trigger.sql (2.76ms)19762026/09/23 13:34:13 OK 20251218171726_add_pins.sql (3.8ms)19772026/09/23 13:34:13 OK 3_commit_push.sql (2.46ms)19782026/09/23 13:34:13 goose: up to current file version: 319792026/09/23 13:34:13 OK 20251218171726_add_pins.sql (3.86ms)19802026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)19812026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)19822026/09/23 13:34:13 OK 20260905000000_add_claims.sql (3.82ms)19832026/09/23 13:34:13 OK 20260905000000_add_claims.sql (3.4ms)19842026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (1.97ms)19852026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (2.72ms)19862026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (2.13ms)19872026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000019882026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (2.38ms)19892026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000019902026/09/23 13:34:13 OK 1_commit_pending_closure.sql (2.95ms)19912026/09/23 13:34:13 OK 1_commit_pending_closure.sql (2.59ms)19922026/09/23 13:34:13 OK 2_object_stats_trigger.sql (2.34ms)19932026/09/23 13:34:13 OK 2_object_stats_trigger.sql (1.89ms)19942026/09/23 13:34:13 OK 3_commit_push.sql (1.52ms)19952026/09/23 13:34:13 goose: up to current file version: 31996=== CONT TestIsValidCachePath/narinfo1997=== CONT TestIsValidCachePath/wrong_extension1998=== CONT TestIsValidCachePath/leading_slash1999=== CONT TestIsValidCachePath/empty2000=== CONT TestIsValidCachePath/random_path2001=== CONT TestIsValidCachePath/short_hash2002=== CONT TestIsValidCachePath/invalid_char_u2003=== CONT TestIsValidCachePath/invalid_char_e2004=== CONT TestIsValidCachePath/traversal_in_middle2005=== CONT TestIsValidCachePath/traversal_parent2006=== CONT TestIsValidCachePath/nar_uncompressed2007=== CONT TestIsValidCachePath/nar_bz22008=== CONT TestIsValidCachePath/nar_xz2009=== CONT TestIsValidCachePath/nar_zst2010=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2011=== CONT TestIsValidCachePath/nix-cache-info2012=== CONT TestIsValidCachePath/index.html2013=== CONT TestIsValidCachePath/realisation2014=== CONT TestIsValidCachePath/ls2015=== CONT TestIsValidCachePath/log2016--- PASS: TestIsValidCachePath (0.00s)2017 --- PASS: TestIsValidCachePath/narinfo (0.00s)2018 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2019 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2020 --- PASS: TestIsValidCachePath/empty (0.00s)2021 --- PASS: TestIsValidCachePath/random_path (0.00s)2022 --- PASS: TestIsValidCachePath/short_hash (0.00s)2023 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2024 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2025 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2026 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2027 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2028 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2029 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2030 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2031 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2032 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2033 --- PASS: TestIsValidCachePath/index.html (0.00s)2034 --- PASS: TestIsValidCachePath/realisation (0.00s)2035 --- PASS: TestIsValidCachePath/ls (0.00s)2036 --- PASS: TestIsValidCachePath/log (0.00s)20372026/09/23 13:34:13 OK 3_commit_push.sql (1.7ms)2038=== CONT TestParseSingleRange/none20392026/09/23 13:34:13 goose: up to current file version: 32040=== CONT TestParseSingleRange/start_far_past_EOF2041=== CONT TestParseSingleRange/start_past_EOF2042=== CONT TestParseSingleRange/single_byte2043=== CONT TestParseSingleRange/suffix_exceeds_size2044=== CONT TestParseSingleRange/suffix2045=== CONT TestParseSingleRange/end_clamped_to_size2046=== CONT TestParseSingleRange/open-ended2047=== CONT TestParseSingleRange/closed2048=== CONT TestParseSingleRange/malformed_end_before_start2049=== CONT TestParseSingleRange/malformed_both_empty2050=== CONT TestParseSingleRange/malformed_no_dash2051=== CONT TestParseSingleRange/multi-range_ignored2052=== CONT TestParseSingleRange/unknown_unit2053=== CONT TestClientErrorHandling/InvalidStorePath2054--- PASS: TestParseSingleRange (0.00s)2055 --- PASS: TestParseSingleRange/none (0.00s)2056 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2057 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2058 --- PASS: TestParseSingleRange/single_byte (0.00s)2059 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2060 --- PASS: TestParseSingleRange/suffix (0.00s)2061 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2062 --- PASS: TestParseSingleRange/open-ended (0.00s)2063 --- PASS: TestParseSingleRange/closed (0.00s)2064 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2065 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2066 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2067 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2068 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2069=== CONT TestClientErrorHandling/ServerNotAvailable2070--- PASS: TestReadProxyConditionalGet (0.59s)2071=== CONT TestClientErrorHandling/InvalidAuthToken20722026-09-23 13:34:13.248 UTC [717] ERROR: relation "goose_db_version" does not exist at character 3620732026-09-23 13:34:13.248 UTC [717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20742026/09/23 13:34:13 OK 20241026095416_initial_model.sql (11.77ms)20752026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (2.42ms)20762026/09/23 13:34:13 OK 20251218171726_add_pins.sql (4.78ms)20772026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)20782026/09/23 13:34:13 OK 20260905000000_add_claims.sql (4.03ms)20792026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (3.06ms)20802026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (3.22ms)20812026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000020822026/09/23 13:34:13 OK 1_commit_pending_closure.sql (2.62ms)20832026/09/23 13:34:13 OK 2_object_stats_trigger.sql (1.72ms)20842026/09/23 13:34:13 OK 3_commit_push.sql (1.76ms)20852026/09/23 13:34:13 goose: up to current file version: 320862026-09-23 13:34:13.301 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3620872026-09-23 13:34:13.301 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20882026/09/23 13:34:13 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/present20892026/09/23 13:34:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20902026/09/23 13:34:13 WARN Refused reserved pin name=worker-x86_64-linux20912026/09/23 13:34:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20922026/09/23 13:34:13 INFO Received create pin request method=POST path=/api/pins/my-app20932026/09/23 13:34:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2094--- PASS: TestCreatePin_ReservedPins (0.82s)2095=== CONT TestPush_RejectsBadRequests/no_roots20962026/09/23 13:34:13 INFO Received push request method=POST path=/api/pushes2097=== CONT TestPush_RejectsBadRequests/bad_root20982026/09/23 13:34:13 INFO Received push request method=POST path=/api/pushes2099=== CONT TestPush_RejectsBadRequests/no_objects21002026/09/23 13:34:13 INFO Received push request method=POST path=/api/pushes2101=== CONT TestPush_RejectsBadRequests/root_not_in_objects21022026/09/23 13:34:13 INFO Received push request method=POST path=/api/pushes2103=== CONT TestResolveDBConnectionString/flag_wins2104--- PASS: TestPush_RejectsBadRequests (0.66s)2105 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2106 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2107 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2108 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2109=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2110=== CONT TestResolveDBConnectionString/nothing_configured2111=== CONT TestResolveDBConnectionString/missing_file_is_an_error2112=== CONT TestResolveDBConnectionString/file_when_flag_empty2113=== CONT TestCacheConfigHandler/full_config,_no_issuer21142026/09/23 13:34:13 OK 20241026095416_initial_model.sql (7.92ms)2115=== CONT TestCacheConfigHandler/no_signing_keys2116--- PASS: TestResolveDBConnectionString (0.00s)2117 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2118 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2119 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2120 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2121 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2122=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2123=== CONT TestCacheConfigHandler/no_cache_url_configured2124--- PASS: TestCacheConfigHandler (0.00s)2125 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2126 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2127 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2128 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)21292026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)21302026/09/23 13:34:13 OK 20251218171726_add_pins.sql (2.4ms)21312026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (2.07ms)21322026/09/23 13:34:13 OK 20260905000000_add_claims.sql (2.75ms)21332026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (1.5ms)21342026-09-23 13:34:13.327 UTC [755] ERROR: relation "goose_db_version" does not exist at character 3621352026-09-23 13:34:13.327 UTC [755] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21362026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (1.37ms)21372026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000021382026/09/23 13:34:13 OK 1_commit_pending_closure.sql (1.58ms)21392026/09/23 13:34:13 OK 2_object_stats_trigger.sql (1.03ms)21402026/09/23 13:34:13 OK 3_commit_push.sql (834.29µs)21412026/09/23 13:34:13 goose: up to current file version: 32142--- PASS: TestReadProxyHead (0.58s)21432026/09/23 13:34:13 OK 20241026095416_initial_model.sql (13.23ms)21442026/09/23 13:34:13 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)21452026/09/23 13:34:13 OK 20251218171726_add_pins.sql (3.37ms)21462026/09/23 13:34:13 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)2147--- PASS: TestObjectStatsTrigger (0.58s)21482026/09/23 13:34:13 OK 20260905000000_add_claims.sql (3.3ms)21492026/09/23 13:34:13 OK 20260920000000_drop_claims.sql (2.29ms)21502026/09/23 13:34:13 OK 20260923120000_add_pushes.sql (1.71ms)21512026/09/23 13:34:13 goose: successfully migrated database to version: 2026092312000021522026/09/23 13:34:13 OK 1_commit_pending_closure.sql (2.05ms)21532026/09/23 13:34:13 OK 2_object_stats_trigger.sql (925.23µs)21542026/09/23 13:34:13 OK 3_commit_push.sql (886.45µs)21552026/09/23 13:34:13 goose: up to current file version: 321562026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures21572026/09/23 13:34:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.948444ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2158=== NAME TestClientMultipleUploads2159 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads562298193/001/store/szcdc93q35y8w7xv48f8fzjznns2wh6g-test-file-0.txt2160 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads562298193/001/store/pzwp4yjkxq0zmkfbbii0h282n7rkpm7b-test-file-1.txt2161--- PASS: TestCacheStatsHandler (0.56s)2162=== NAME TestClientIntegration2163 client_integration_test.go:286: Created store path: /build/TestClientIntegration503957969/002/store/xi86mj7zxk47as4vmqgv31aazamxw1hg-test-file.txt21642026/09/23 13:34:13 INFO Received cleanup request method=DELETE path=/api/pending_closures2165=== NAME TestPinProtectsFromGC2166 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1675607985/001/store/7nwhs2n1hnp604a24qdlsd97mnx1ddx0-pinned-file.txt2167 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1675607985/001/store/vli974ih0c8598dg25jrbhhcbx4f0v08-unpinned-file.txt21682026/09/23 13:34:13 INFO Aborted multipart uploads count=12169--- PASS: TestMultipartCleanup (0.71s)2170=== NAME TestClientMultipleUploads2171 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads562298193/001/store/q8kc4czzbv1qjnqyb4ssif3nk45r944m-test-file-2.txt2172--- PASS: TestService_ReadAuthMiddleware (0.56s)2173--- PASS: TestService_ReadScope_PublicByDefault (0.55s)21742026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures21752026/09/23 13:34:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21762026/09/23 13:34:13 INFO Uploading xi86mj7zxk47as4vmqgv31aazamxw1hg-test-file.txt (152B)21772026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures21782026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"21792026/09/23 13:34:13 WARN Failed to register uploaded object key=xi86mj7zxk47as4vmqgv31aazamxw1hg.ls error="server returned 404: 404 page not found\n"21802026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21812026/09/23 13:34:13 INFO Signed narinfos id=1 count=121822026/09/23 13:34:13 INFO Uploading 1 narinfos21832026/09/23 13:34:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21842026/09/23 13:34:13 INFO Uploading 7nwhs2n1hnp604a24qdlsd97mnx1ddx0-pinned-file.txt (128B)21852026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21862026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures21872026/09/23 13:34:13 WARN Failed to register uploaded object key=xi86mj7zxk47as4vmqgv31aazamxw1hg.narinfo error="server returned 404: 404 page not found\n"21882026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"21892026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21902026/09/23 13:34:13 WARN Failed to register uploaded object key=7nwhs2n1hnp604a24qdlsd97mnx1ddx0.ls error="server returned 404: 404 page not found\n"21912026/09/23 13:34:13 INFO Signed narinfos id=1 count=121922026/09/23 13:34:13 INFO Uploading 1 narinfos21932026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures21942026/09/23 13:34:13 INFO Completed upload id=121952026/09/23 13:34:13 INFO Upload complete. (62ms)21962026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures21972026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21982026/09/23 13:34:13 WARN Failed to register uploaded object key=7nwhs2n1hnp604a24qdlsd97mnx1ddx0.narinfo error="server returned 404: 404 page not found\n"21992026/09/23 13:34:13 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)22002026/09/23 13:34:13 INFO Uploading pzwp4yjkxq0zmkfbbii0h282n7rkpm7b-test-file-1.txt (160B)22012026/09/23 13:34:13 INFO Uploading szcdc93q35y8w7xv48f8fzjznns2wh6g-test-file-0.txt (160B)22022026/09/23 13:34:13 INFO Uploading q8kc4czzbv1qjnqyb4ssif3nk45r944m-test-file-2.txt (160B)2203=== NAME TestClientCADerivations2204 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4270532424/001/store/jycjk5270rg1f152fs03dcpj05mp7g6v-ca-test22052026/09/23 13:34:13 INFO Completed upload id=122062026/09/23 13:34:13 INFO Upload complete. (61ms)22072026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"22082026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"22092026/09/23 13:34:13 WARN Failed to register uploaded object key=q8kc4czzbv1qjnqyb4ssif3nk45r944m.ls error="server returned 404: 404 page not found\n"22102026/09/23 13:34:13 WARN Failed to register uploaded object key=pzwp4yjkxq0zmkfbbii0h282n7rkpm7b.ls error="server returned 404: 404 page not found\n"22112026/09/23 13:34:13 WARN Failed to register uploaded object key=szcdc93q35y8w7xv48f8fzjznns2wh6g.ls error="server returned 404: 404 page not found\n"22122026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22132026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"22142026/09/23 13:34:13 INFO Signed narinfos id=2 count=122152026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign22162026/09/23 13:34:13 INFO Signed narinfos id=3 count=122172026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22182026/09/23 13:34:13 INFO Signed narinfos id=1 count=122192026/09/23 13:34:13 INFO Uploading 3 narinfos22202026/09/23 13:34:13 WARN Failed to register uploaded object key=pzwp4yjkxq0zmkfbbii0h282n7rkpm7b.narinfo error="server returned 404: 404 page not found\n"22212026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22222026/09/23 13:34:13 WARN Failed to register uploaded object key=szcdc93q35y8w7xv48f8fzjznns2wh6g.narinfo error="server returned 404: 404 page not found\n"22232026/09/23 13:34:13 WARN Failed to register uploaded object key=q8kc4czzbv1qjnqyb4ssif3nk45r944m.narinfo error="server returned 404: 404 page not found\n"22242026/09/23 13:34:13 INFO Completed upload id=122252026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete2226=== NAME TestOrphanedObjectsGC2227 orphaned_objects_gc_test.go:290: GC Test Summary:2228 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2229 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2230 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2231 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2232 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2233--- PASS: TestOrphanedObjectsGC (0.91s)22342026/09/23 13:34:13 INFO Completed upload id=222352026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete22362026/09/23 13:34:13 INFO Completed upload id=322372026/09/23 13:34:13 INFO Upload complete. (75ms)2238=== NAME TestClientMultipleUploads2239 client_integration_test.go:369: Uploaded 3 paths in 106.46721ms22402026/09/23 13:34:13 INFO All 1 paths already cached2241=== NAME TestClientIntegration2242 client_integration_test.go:312: Retrieved narinfo from S3:2243 StorePath: /build/TestClientIntegration503957969/002/store/xi86mj7zxk47as4vmqgv31aazamxw1hg-test-file.txt2244 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2245 Compression: zstd2246 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12247 NarSize: 1522248 References: 2249 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12250=== NAME TestClientCADerivations2251 client_ca_test.go:139: Found 1 dependencies (including self)2252=== NAME TestClientIntegration2253 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2254 client_integration_test.go:313: Decompressed .ls content (64 bytes):2255 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2256 client_integration_test.go:316: Testing garbage collection...2257--- PASS: TestClientMultipleUploads (0.82s)22582026/09/23 13:34:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"22592026/09/23 13:34:13 WARN mTLS auth: bound subjects configured but subject DN unavailable22602026/09/23 13:34:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2261--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.55s)22622026/09/23 13:34:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.426003ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2263=== RUN TestService_RequireScope_OIDC/builder_may_write2264=== PAUSE TestService_RequireScope_OIDC/builder_may_write2265=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2266=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2267=== RUN TestService_RequireScope_OIDC/ops_may_admin2268=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2269=== RUN TestService_RequireScope_OIDC/ops_may_not_write2270=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2271=== RUN TestService_RequireScope_OIDC/reader_may_not_write2272=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2273=== RUN TestService_RequireScope_OIDC/static_token_may_admin2274=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2275=== RUN TestService_RequireScope_OIDC/static_token_may_write2276=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2277=== RUN TestService_RequireScope_OIDC/reader_may_read2278=== PAUSE TestService_RequireScope_OIDC/reader_may_read2279=== RUN TestService_RequireScope_OIDC/writer_implies_read2280=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2281=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2282=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2283=== CONT TestService_RequireScope_OIDC/builder_may_write2284=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2285=== CONT TestService_RequireScope_OIDC/static_token_may_admin2286=== CONT TestService_RequireScope_OIDC/reader_may_read2287=== CONT TestService_RequireScope_OIDC/writer_implies_read2288=== CONT TestService_RequireScope_OIDC/ops_may_not_write2289=== CONT TestService_RequireScope_OIDC/static_token_may_write2290=== CONT TestService_RequireScope_OIDC/reader_may_not_write2291=== CONT TestService_RequireScope_OIDC/ops_may_admin2292=== CONT TestService_RequireScope_OIDC/builder_may_not_admin22932026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures2294--- PASS: TestService_RequireScope_OIDC (0.59s)2295 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2296 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2297 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2298 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2299 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2300 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2301 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2302 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2303 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2304 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)23052026/09/23 13:34:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23062026/09/23 13:34:13 INFO Uploading vli974ih0c8598dg25jrbhhcbx4f0v08-unpinned-file.txt (128B)23072026/09/23 13:34:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures23082026/09/23 13:34:13 INFO Garbage collection started23092026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"23102026/09/23 13:34:13 WARN Failed to register uploaded object key=vli974ih0c8598dg25jrbhhcbx4f0v08.ls error="server returned 404: 404 page not found\n"23112026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign23122026/09/23 13:34:13 INFO Signed narinfos id=2 count=123132026/09/23 13:34:13 INFO Uploading 1 narinfos23142026/09/23 13:34:13 INFO Aborted multipart uploads count=023152026/09/23 13:34:13 WARN Force mode enabled - objects will be deleted immediately without grace period23162026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23172026/09/23 13:34:13 WARN Failed to register uploaded object key=vli974ih0c8598dg25jrbhhcbx4f0v08.narinfo error="server returned 404: 404 page not found\n"23182026/09/23 13:34:13 INFO Completed upload id=223192026/09/23 13:34:13 INFO Upload complete. (44ms)2320--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.57s)23212026/09/23 13:34:13 INFO Received create pin request method=POST path=/api/pins/myapp2322=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2323=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2324=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2325=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2326=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2327=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2328=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2329=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2330=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2331=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2332=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected23332026/09/23 13:34:13 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]2334=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured23352026/09/23 13:34:13 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1675607985/001/store/7nwhs2n1hnp604a24qdlsd97mnx1ddx0-pinned-file.txt narinfo_key=7nwhs2n1hnp604a24qdlsd97mnx1ddx0.narinfo23362026/09/23 13:34:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures23372026/09/23 13:34:13 INFO Garbage collection started23382026/09/23 13:34:13 WARN Authentication failed token_preview=eyJhbGciOi...urGmh3gHvw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]23392026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures2340--- PASS: TestService_AuthMiddleware_OIDC (0.77s)2341 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2342 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2343 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2344 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)23452026/09/23 13:34:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23462026/09/23 13:34:13 INFO Uploading jycjk5270rg1f152fs03dcpj05mp7g6v-ca-test (144B)23472026/09/23 13:34:13 INFO Aborted multipart uploads count=023482026/09/23 13:34:13 WARN Force mode enabled - objects will be deleted immediately without grace period23492026/09/23 13:34:13 WARN Failed to register uploaded object key=log/d867pqpfwk23p2jzkycjhlnc6z7cy895-ca-test.drv error="server returned 404: 404 page not found\n"23502026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures23512026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"23522026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23532026/09/23 13:34:13 WARN Failed to register uploaded object key=jycjk5270rg1f152fs03dcpj05mp7g6v.ls error="server returned 404: 404 page not found\n"23542026/09/23 13:34:13 INFO Signed narinfos id=1 count=123552026/09/23 13:34:13 INFO Uploading 1 narinfos23562026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23572026/09/23 13:34:13 WARN Failed to register uploaded object key=jycjk5270rg1f152fs03dcpj05mp7g6v.narinfo error="server returned 404: 404 page not found\n"23582026/09/23 13:34:13 INFO Completed upload id=123592026/09/23 13:34:13 INFO Upload complete. (84ms)2360=== NAME TestClientCADerivations2361 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4270532424/001/store/jycjk5270rg1f152fs03dcpj05mp7g6v-ca-test2362 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2363 Compression: zstd2364 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2365 NarSize: 1442366 References: 2367 Deriver: /build/TestClientCADerivations4270532424/001/store/d867pqpfwk23p2jzkycjhlnc6z7cy895-ca-test.drv2368 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2369 client_ca_test.go:185: Checking for realisation files in S3...2370 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2371 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2372=== NAME TestClientWithDependencies2373 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1773597654/001/store/7v9w5v35pqnkiimgwb63yg7g5kh972lq-test-script2374 client_integration_test.go:615: Found 1 dependencies (including self)23752026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures23762026/09/23 13:34:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23772026/09/23 13:34:13 INFO Uploading 6rsqp4lqmzs7mp13v9iz87z37dy40l7s-shared-dep (136B)23782026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23792026/09/23 13:34:13 WARN Failed to register uploaded object key=6rsqp4lqmzs7mp13v9iz87z37dy40l7s.ls error="server returned 404: 404 page not found\n"23802026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign23812026/09/23 13:34:13 INFO Signed narinfos id=2 count=123822026/09/23 13:34:13 INFO Uploading 1 narinfos23832026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23842026/09/23 13:34:13 WARN Failed to register uploaded object key=6rsqp4lqmzs7mp13v9iz87z37dy40l7s.narinfo error="server returned 404: 404 page not found\n"23852026/09/23 13:34:13 INFO Completed upload id=223862026/09/23 13:34:13 INFO Upload complete. (51ms)23872026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures23882026/09/23 13:34:13 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)23892026/09/23 13:34:13 INFO Uploading 6rsqp4lqmzs7mp13v9iz87z37dy40l7s-shared-dep (136B)23902026/09/23 13:34:13 INFO Uploading c8k7gs6sfql1vphik0mkg32rpzv5qcc0-top (224B)23912026/09/23 13:34:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23922026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/1m3clqynp6k2h74ssbcki1i11c2rpghad4ppjigk677fg4zx7f08.nar.zst error="server returned 404: 404 page not found\n"23932026/09/23 13:34:13 WARN Failed to register uploaded object key=c8k7gs6sfql1vphik0mkg32rpzv5qcc0.ls error="server returned 404: 404 page not found\n"23942026/09/23 13:34:13 WARN Failed to register uploaded object key=6rsqp4lqmzs7mp13v9iz87z37dy40l7s.ls error="server returned 404: 404 page not found\n"23952026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23962026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign23972026/09/23 13:34:13 INFO Signed narinfos id=3 count=123982026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23992026/09/23 13:34:13 INFO Signed narinfos id=1 count=124002026/09/23 13:34:13 INFO Uploading 2 narinfos2401=== NAME TestClientCADerivations2402 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2403 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2404 error: binary cache 's3://bucket53?endpoint=http://localhost:38875®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4270532424/001/store'2405 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 124062026/09/23 13:34:13 WARN Failed to register uploaded object key=c8k7gs6sfql1vphik0mkg32rpzv5qcc0.narinfo error="server returned 404: 404 page not found\n"24072026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24082026/09/23 13:34:13 WARN Failed to register uploaded object key=6rsqp4lqmzs7mp13v9iz87z37dy40l7s.narinfo error="server returned 404: 404 page not found\n"2409--- PASS: TestClientCADerivations (0.88s)24102026/09/23 13:34:13 INFO Completed upload id=124112026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete24122026/09/23 13:34:13 INFO Completed upload id=324132026/09/23 13:34:13 INFO Upload complete. (136ms)2414=== NAME TestClientSharedPathCommittedMidPush2415 client_integration_test.go:680: Retrieved narinfo from S3:2416 StorePath: /build/TestClientSharedPathCommittedMidPush1117252739/001/store/6rsqp4lqmzs7mp13v9iz87z37dy40l7s-shared-dep2417 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2418 Compression: zstd2419 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822420 NarSize: 1362421 References: 2422 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2423 client_integration_test.go:680: Retrieved narinfo from S3:2424 StorePath: /build/TestClientSharedPathCommittedMidPush1117252739/001/store/c8k7gs6sfql1vphik0mkg32rpzv5qcc0-top2425 URL: nar/1m3clqynp6k2h74ssbcki1i11c2rpghad4ppjigk677fg4zx7f08.nar.zst2426 Compression: zstd2427 NarHash: sha256:1m3clqynp6k2h74ssbcki1i11c2rpghad4ppjigk677fg4zx7f082428 NarSize: 2242429 References: /build/TestClientSharedPathCommittedMidPush1117252739/001/store/6rsqp4lqmzs7mp13v9iz87z37dy40l7s-shared-dep2430 CA: text:sha256:1xjxq0c8bij82bkvmvgmjs36lmzsgfd0sbf3f36rpnzbz6g7qajs2431--- PASS: TestClientSharedPathCommittedMidPush (0.82s)24322026/09/23 13:34:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"24332026/09/23 13:34:13 INFO Received uploads request method=POST path=/api/pending_closures24342026/09/23 13:34:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24352026/09/23 13:34:13 INFO Uploading 7v9w5v35pqnkiimgwb63yg7g5kh972lq-test-script (136B)24362026/09/23 13:34:13 WARN Failed to register uploaded object key=7v9w5v35pqnkiimgwb63yg7g5kh972lq.ls error="server returned 404: 404 page not found\n"24372026/09/23 13:34:13 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"24382026/09/23 13:34:13 WARN Failed to register uploaded object key=log/348jfbx6xm1hg1wlb3v6gy1448wz3s0b-test-script.drv error="server returned 404: 404 page not found\n"24392026/09/23 13:34:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24402026/09/23 13:34:13 INFO Signed narinfos id=1 count=124412026/09/23 13:34:13 INFO Uploading 1 narinfos24422026/09/23 13:34:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24432026/09/23 13:34:13 WARN Failed to register uploaded object key=7v9w5v35pqnkiimgwb63yg7g5kh972lq.narinfo error="server returned 404: 404 page not found\n"24442026/09/23 13:34:13 INFO Completed upload id=124452026/09/23 13:34:13 INFO Upload complete. (58ms)2446=== NAME TestClientWithDependencies2447 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1773597654/001/store) requires matching store prefix2448--- PASS: TestClientWithDependencies (0.77s)24492026/09/23 13:34:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=831.031655ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2450--- PASS: TestUploadHandlersRejectOversizedBody (0.25s)2451 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2452 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2453 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.36s)2454=== NAME TestOrphanedObjectsGCStressTest2455 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2456 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion24572026/09/23 13:34:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.634609051s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24582026/09/23 13:34:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=024592026/09/23 13:34:14 INFO Vacuumed table table=pending_closures24602026/09/23 13:34:14 INFO Vacuumed table table=pending_objects24612026/09/23 13:34:14 INFO Vacuumed table table=multipart_uploads24622026/09/23 13:34:14 INFO Vacuumed table table=closures24632026/09/23 13:34:14 INFO Vacuumed table table=objects24642026/09/23 13:34:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=024652026/09/23 13:34:14 INFO Vacuumed table table=pending_closures24662026/09/23 13:34:14 INFO Vacuumed table table=pending_objects24672026/09/23 13:34:14 INFO Vacuumed table table=multipart_uploads24682026/09/23 13:34:14 INFO Vacuumed table table=closures24692026/09/23 13:34:14 INFO Vacuumed table table=objects2470 orphaned_objects_gc_test.go:509: Stress test completed successfully:2471 orphaned_objects_gc_test.go:510: - Active objects preserved: 202472 orphaned_objects_gc_test.go:511: - Objects deleted: 2102473 orphaned_objects_gc_test.go:512: - Total GC'd: 2102474--- PASS: TestOrphanedObjectsGCStressTest (2.44s)24752026/09/23 13:34:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02476=== NAME TestClientIntegration2477 client_integration_test.go:323: Objects in database after GC:2478 client_integration_test.go:323: Successfully deleted all objects with GC --force2479--- PASS: TestClientIntegration (2.83s)24802026/09/23 13:34:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02481=== NAME TestPinProtectsFromGC2482 client_integration_test.go:794: Pin successfully protected closure from garbage collection2483--- PASS: TestPinProtectsFromGC (2.91s)24842026/09/23 13:34:15 WARN Rate limiter enabled after throttle name=s3-test rate=524852026/09/23 13:34:15 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2486=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2487 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102488 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002489--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.23s)24902026/09/23 13:34:16 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-config24912026/09/23 13:34:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.102884ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24922026/09/23 13:34:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.680036ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24932026/09/23 13:34:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=762.731008ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24942026/09/23 13:34:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.48944882s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24952026/09/23 13:34:19 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"24962026/09/23 13:34:19 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_closures24972026/09/23 13:34:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.552691ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24982026/09/23 13:34:19 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=391.373976ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24992026/09/23 13:34:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=790.112839ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25002026/09/23 13:34:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.584595495s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2501--- PASS: TestClientErrorHandling (0.00s)2502 --- PASS: TestClientErrorHandling/InvalidStorePath (0.52s)2503 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.60s)2504 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.29s)2505PASS25062026-09-23 13:34:22.804 UTC [128] LOG: received smart shutdown request25072026-09-23 13:34:22.811 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 125082026-09-23 13:34:22.827 UTC [133] LOG: shutting down25092026-09-23 13:34:22.828 UTC [133] LOG: checkpoint starting: shutdown immediate25102026-09-23 13:34:23.388 UTC [133] LOG: checkpoint complete: wrote 11076 buffers (67.6%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.210 s, sync=0.334 s, total=0.561 s; sync files=21203, longest=0.004 s, average=0.001 s; distance=288380 kB, estimate=288380 kB; lsn=0/13105070, redo lsn=0/1310507025112026-09-23 13:34:23.486 UTC [128] LOG: database system is shut down2512Running OIDC tests...2513=== RUN TestAudienceForIssuer2514=== PAUSE TestAudienceForIssuer2515=== RUN TestGlobMatch2516=== PAUSE TestGlobMatch2517=== RUN TestValidateToken_ValidToken2518=== PAUSE TestValidateToken_ValidToken2519=== RUN TestValidateToken_WrongAudience2520=== PAUSE TestValidateToken_WrongAudience2521=== RUN TestValidateToken_Expired2522=== PAUSE TestValidateToken_Expired2523=== RUN TestValidateToken_BoundClaimsMismatch2524=== PAUSE TestValidateToken_BoundClaimsMismatch2525=== RUN TestValidateToken_BoundSubjectMismatch2526=== PAUSE TestValidateToken_BoundSubjectMismatch2527=== RUN TestValidateToken_MultipleProviders2528=== PAUSE TestValidateToken_MultipleProviders2529=== RUN TestValidateToken_NoMatchingProvider2530=== PAUSE TestValidateToken_NoMatchingProvider2531=== RUN TestValidateToken_KubernetesServiceAccount2532=== PAUSE TestValidateToken_KubernetesServiceAccount2533=== RUN TestNewValidator_KubernetesRequiresCA2534=== PAUSE TestNewValidator_KubernetesRequiresCA2535=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2536=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2537=== RUN TestPins_ReservedForMatchingRule2538=== PAUSE TestPins_ReservedForMatchingRule2539=== RUN TestPins_TopLevelShorthand2540=== PAUSE TestPins_TopLevelShorthand2541=== RUN TestPins_ConfigValidation2542=== PAUSE TestPins_ConfigValidation2543=== RUN TestScopes_LegacyProviderDefaultsToWrite2544=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2545=== RUN TestScopes_Rules2546=== PAUSE TestScopes_Rules2547=== RUN TestScopes_ConfigValidation2548=== PAUSE TestScopes_ConfigValidation2549=== CONT TestAudienceForIssuer2550=== CONT TestPins_ConfigValidation2551--- PASS: TestAudienceForIssuer (0.00s)2552=== CONT TestValidateToken_NoMatchingProvider2553=== CONT TestValidateToken_KubernetesServiceAccount2554=== CONT TestScopes_Rules2555=== CONT TestValidateToken_Expired2556=== CONT TestScopes_LegacyProviderDefaultsToWrite2557=== CONT TestScopes_ConfigValidation2558=== CONT TestPins_ReservedForMatchingRule2559=== CONT TestValidateToken_ValidToken2560=== CONT TestValidateToken_BoundSubjectMismatch2561=== CONT TestValidateToken_WrongAudience2562=== CONT TestGlobMatch2563--- PASS: TestScopes_ConfigValidation (0.00s)2564--- PASS: TestPins_ConfigValidation (0.00s)2565=== CONT TestValidateToken_MultipleProviders2566=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2567=== CONT TestNewValidator_KubernetesRequiresCA2568=== CONT TestValidateToken_BoundClaimsMismatch2569=== CONT TestPins_TopLevelShorthand2570=== RUN TestGlobMatch/foo_foo2571=== PAUSE TestGlobMatch/foo_foo2572=== RUN TestGlobMatch/foo_bar2573=== PAUSE TestGlobMatch/foo_bar2574=== RUN TestGlobMatch/*_2575=== PAUSE TestGlobMatch/*_2576=== RUN TestGlobMatch/*_anything2577=== PAUSE TestGlobMatch/*_anything2578=== RUN TestGlobMatch/foo*_foo2579=== PAUSE TestGlobMatch/foo*_foo2580=== RUN TestGlobMatch/foo*_foobar2581=== PAUSE TestGlobMatch/foo*_foobar2582=== RUN TestGlobMatch/foo*_bar2583=== PAUSE TestGlobMatch/foo*_bar2584=== RUN TestGlobMatch/*bar_bar2585=== PAUSE TestGlobMatch/*bar_bar2586=== RUN TestGlobMatch/*bar_foobar2587=== PAUSE TestGlobMatch/*bar_foobar2588=== RUN TestGlobMatch/*bar_foo2589=== PAUSE TestGlobMatch/*bar_foo2590=== RUN TestGlobMatch/foo*bar_foobar2591=== PAUSE TestGlobMatch/foo*bar_foobar2592=== RUN TestGlobMatch/foo*bar_foo123bar2593=== PAUSE TestGlobMatch/foo*bar_foo123bar2594=== RUN TestGlobMatch/foo*bar_foobarbaz2595=== PAUSE TestGlobMatch/foo*bar_foobarbaz2596=== RUN TestGlobMatch/*/*_foo/bar2597=== PAUSE TestGlobMatch/*/*_foo/bar2598=== RUN TestGlobMatch/*/*_foo2599=== PAUSE TestGlobMatch/*/*_foo2600=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2601=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2602=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02603=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02604=== RUN TestGlobMatch/refs/*/main_refs/heads/main2605=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2606=== RUN TestGlobMatch/fo?_foo2607=== PAUSE TestGlobMatch/fo?_foo2608=== RUN TestGlobMatch/fo?_fo2609=== PAUSE TestGlobMatch/fo?_fo2610=== RUN TestGlobMatch/fo?_fooo2611=== PAUSE TestGlobMatch/fo?_fooo2612=== RUN TestGlobMatch/?oo_foo2613=== PAUSE TestGlobMatch/?oo_foo2614=== RUN TestGlobMatch/?oo_boo2615=== PAUSE TestGlobMatch/?oo_boo2616=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2617=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2618=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2619=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2620=== CONT TestGlobMatch/foo_foo2621=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2622=== CONT TestGlobMatch/?oo_boo2623=== CONT TestGlobMatch/?oo_foo2624=== CONT TestGlobMatch/fo?_fooo2625=== CONT TestGlobMatch/fo?_fo2626=== CONT TestGlobMatch/fo?_foo2627=== CONT TestGlobMatch/refs/*/main_refs/heads/main2628=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02629=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2630=== CONT TestGlobMatch/*/*_foo2631=== CONT TestGlobMatch/*/*_foo/bar2632=== CONT TestGlobMatch/foo*bar_foobarbaz2633=== CONT TestGlobMatch/foo*bar_foo123bar2634=== CONT TestGlobMatch/*bar_foobar2635=== CONT TestGlobMatch/*bar_bar2636=== CONT TestGlobMatch/foo*_bar2637=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2638=== CONT TestGlobMatch/foo*_foobar2639=== CONT TestGlobMatch/foo*_foo2640=== CONT TestGlobMatch/*_anything2641=== CONT TestGlobMatch/*_2642=== CONT TestGlobMatch/foo_bar2643=== CONT TestGlobMatch/*bar_foo2644=== CONT TestGlobMatch/foo*bar_foobar2645--- PASS: TestGlobMatch (0.00s)2646 --- PASS: TestGlobMatch/foo_foo (0.00s)2647 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2648 --- PASS: TestGlobMatch/?oo_boo (0.00s)2649 --- PASS: TestGlobMatch/?oo_foo (0.00s)2650 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2651 --- PASS: TestGlobMatch/fo?_fo (0.00s)2652 --- PASS: TestGlobMatch/fo?_foo (0.00s)2653 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2654 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2655 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2656 --- PASS: TestGlobMatch/*/*_foo (0.00s)2657 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2658 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2659 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2660 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2661 --- PASS: TestGlobMatch/*bar_bar (0.00s)2662 --- PASS: TestGlobMatch/foo*_bar (0.00s)2663 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2664 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2665 --- PASS: TestGlobMatch/foo*_foo (0.00s)2666 --- PASS: TestGlobMatch/*_anything (0.00s)2667 --- PASS: TestGlobMatch/*_ (0.00s)2668 --- PASS: TestGlobMatch/foo_bar (0.00s)2669 --- PASS: TestGlobMatch/*bar_foo (0.00s)2670 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)26712026/09/23 13:34:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44431/oidc2672--- PASS: TestScopes_Rules (0.06s)26732026/09/23 13:34:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46797/oidc2674--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)26752026/09/23 13:34:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39159/oidc2676--- PASS: TestPins_ReservedForMatchingRule (0.10s)26772026/09/23 13:34:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38581/oidc26782026/09/23 13:34:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46423/oidc2679--- PASS: TestPins_TopLevelShorthand (0.11s)26802026/09/23 13:34:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46099/oidc2681--- PASS: TestValidateToken_WrongAudience (0.12s)2682--- PASS: TestValidateToken_BoundSubjectMismatch (0.12s)26832026/09/23 13:34:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33043/oidc2684--- PASS: TestValidateToken_ValidToken (0.13s)26852026/09/23 13:34:24 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:456532686--- PASS: TestValidateToken_KubernetesServiceAccount (0.15s)26872026/09/23 13:34:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42039/oidc2688--- PASS: TestValidateToken_BoundClaimsMismatch (0.19s)26892026/09/23 13:34:24 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12326902026/09/23 13:34:24 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33231/oidc26912026/09/23 13:34:24 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:43593/oidc2692--- PASS: TestValidateToken_MultipleProviders (0.20s)2693--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.21s)26942026/09/23 13:34:24 http: TLS handshake error from 127.0.0.1:49910: remote error: tls: bad certificate2695--- PASS: TestNewValidator_KubernetesRequiresCA (0.22s)26962026/09/23 13:34:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36131/oidc2697--- PASS: TestValidateToken_Expired (0.24s)26982026/09/23 13:34:24 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33039/oidc2699--- PASS: TestValidateToken_NoMatchingProvider (0.44s)2700PASS2701Running hook tests...2702=== RUN TestSendPathsEmpty2703=== PAUSE TestSendPathsEmpty2704=== RUN TestQueueEnqueueAndFetch2705=== PAUSE TestQueueEnqueueAndFetch2706=== RUN TestQueueDeduplication2707=== PAUSE TestQueueDeduplication2708=== RUN TestQueueRemove2709=== PAUSE TestQueueRemove2710=== RUN TestQueueFetchBatchLimit2711=== PAUSE TestQueueFetchBatchLimit2712=== RUN TestQueueRetryMovesToBack2713=== PAUSE TestQueueRetryMovesToBack2714=== RUN TestQueueFetchRemoveLifecycle2715=== PAUSE TestQueueFetchRemoveLifecycle2716=== RUN TestQueueConcurrentWriters2717=== PAUSE TestQueueConcurrentWriters2718=== RUN TestQueueRemoveLargeClosure2719=== PAUSE TestQueueRemoveLargeClosure2720=== RUN TestServerClientIntegration2721=== PAUSE TestServerClientIntegration2722=== RUN TestServerQueueError2723=== PAUSE TestServerQueueError2724=== RUN TestGetListenerSocketActivation2725 server_test.go:210: === RUN TestGetListenerSocketActivation2726 --- PASS: TestGetListenerSocketActivation (0.00s)2727 PASS2728 2729--- PASS: TestGetListenerSocketActivation (0.01s)2730=== RUN TestDrainIsolatesPoisonPath2731=== PAUSE TestDrainIsolatesPoisonPath2732=== RUN TestRunNotBlockedByPoisonHead2733=== PAUSE TestRunNotBlockedByPoisonHead2734=== RUN TestDrainGivesUpWhenServerDown2735=== PAUSE TestDrainGivesUpWhenServerDown2736=== RUN TestFailedPathPrunedByLaterClosure2737=== PAUSE TestFailedPathPrunedByLaterClosure2738=== RUN TestWorkerUploadsAndRemoves2739=== PAUSE TestWorkerUploadsAndRemoves2740=== RUN TestWorkerSkipsGCdPaths2741=== PAUSE TestWorkerSkipsGCdPaths2742=== RUN TestWorkerPrunesClosureDeps2743=== PAUSE TestWorkerPrunesClosureDeps2744=== RUN TestDrainTimeout2745=== PAUSE TestDrainTimeout2746=== CONT TestSendPathsEmpty2747=== CONT TestDrainIsolatesPoisonPath2748=== CONT TestDrainGivesUpWhenServerDown2749=== CONT TestWorkerUploadsAndRemoves2750=== CONT TestDrainTimeout2751=== CONT TestWorkerPrunesClosureDeps2752--- PASS: TestSendPathsEmpty (0.00s)2753=== CONT TestWorkerSkipsGCdPaths2754=== CONT TestServerQueueError2755=== CONT TestQueueFetchBatchLimit2756=== CONT TestQueueRetryMovesToBack2757=== CONT TestQueueRemove2758=== CONT TestServerClientIntegration2759=== CONT TestQueueRemoveLargeClosure2760=== CONT TestQueueDeduplication2761=== CONT TestQueueConcurrentWriters2762=== CONT TestQueueEnqueueAndFetch2763=== CONT TestQueueFetchRemoveLifecycle27642026/09/23 13:34:24 ERROR Failed to queue paths error="permission denied" count=12765=== CONT TestRunNotBlockedByPoisonHead2766=== CONT TestFailedPathPrunedByLaterClosure2767--- PASS: TestServerQueueError (0.00s)2768--- PASS: TestServerClientIntegration (0.00s)27692026/09/23 13:34:24 INFO Uploading batch count=427702026/09/23 13:34:24 ERROR Upload failed error="upload failed" count=427712026/09/23 13:34:24 INFO Upload queue status pending=227722026/09/23 13:34:24 INFO Upload queue status pending=327732026/09/23 13:34:24 INFO Uploading batch count=227742026/09/23 13:34:24 INFO Uploading batch count=127752026/09/23 13:34:24 ERROR Upload failed error="upload failed" count=127762026/09/23 13:34:24 INFO Upload queue status pending=227772026/09/23 13:34:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1824007398/002/bbb2778--- PASS: TestQueueDeduplication (0.01s)27792026/09/23 13:34:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths821663164/002/nonexistent2780--- PASS: TestQueueFetchBatchLimit (0.01s)27812026/09/23 13:34:24 INFO Uploading batch count=127822026/09/23 13:34:24 INFO Uploading batch count=127832026/09/23 13:34:24 ERROR Upload failed error="upload failed" count=12784--- PASS: TestQueueRemove (0.01s)27852026/09/23 13:34:24 INFO Upload queue status pending=227862026/09/23 13:34:24 INFO Uploading batch count=127872026/09/23 13:34:24 INFO Uploading batch count=227882026/09/23 13:34:24 INFO Uploading batch count=22789--- PASS: TestQueueEnqueueAndFetch (0.01s)27902026/09/23 13:34:24 ERROR Upload failed error="upload failed" count=227912026/09/23 13:34:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3696859111/002/a27922026/09/23 13:34:24 INFO Uploading batch count=127932026/09/23 13:34:24 ERROR Upload failed error="upload failed" count=127942026/09/23 13:34:24 INFO Uploading batch count=127952026/09/23 13:34:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3696859111/002/b2796--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2797--- PASS: TestQueueRetryMovesToBack (0.01s)27982026/09/23 13:34:24 INFO Uploading batch count=127992026/09/23 13:34:24 ERROR Upload failed error="upload failed" count=128002026/09/23 13:34:24 INFO Uploading batch count=128012026/09/23 13:34:24 INFO Uploading batch count=228022026/09/23 13:34:24 ERROR Upload failed error="upload failed" count=228032026/09/23 13:34:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3696859111/002/c28042026/09/23 13:34:24 INFO Uploading batch count=128052026/09/23 13:34:24 ERROR Upload failed error="upload failed" count=128062026/09/23 13:34:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3696859111/002/d28072026/09/23 13:34:24 ERROR Drain finished with paths left in queue remaining=128082026/09/23 13:34:24 INFO Uploading batch count=228092026/09/23 13:34:24 ERROR Upload failed error="upload failed" count=228102026/09/23 13:34:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3696859111/002/e2811--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)28122026/09/23 13:34:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3696859111/002/f28132026/09/23 13:34:24 ERROR Drain finished with paths left in queue remaining=102814--- PASS: TestDrainIsolatesPoisonPath (0.02s)2815--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2816--- PASS: TestWorkerUploadsAndRemoves (0.03s)2817--- PASS: TestWorkerSkipsGCdPaths (0.03s)2818--- PASS: TestWorkerPrunesClosureDeps (0.03s)2819--- PASS: TestQueueRemoveLargeClosure (0.20s)2820--- PASS: TestQueueConcurrentWriters (0.21s)28212026/09/23 13:34:25 ERROR Upload failed error="context deadline exceeded" count=228222026/09/23 13:34:25 ERROR Drain finished with paths left in queue remaining=42823--- PASS: TestDrainTimeout (0.22s)28242026/09/23 13:34:25 INFO Uploading batch count=128252026/09/23 13:34:25 INFO Uploading batch count=128262026/09/23 13:34:25 INFO Uploading batch count=128272026/09/23 13:34:25 ERROR Upload failed error="upload failed" count=128282026/09/23 13:34:25 INFO Uploading batch count=128292026/09/23 13:34:25 ERROR Upload failed error="upload failed" count=128302026/09/23 13:34:25 INFO Uploading batch count=128312026/09/23 13:34:25 ERROR Upload failed error="upload failed" count=128322026/09/23 13:34:25 INFO Uploading batch count=128332026/09/23 13:34:25 ERROR Upload failed error="upload failed" count=128342026/09/23 13:34:25 ERROR Drain finished with paths left in queue remaining=12835--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2836PASS