niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #257
· 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 TestScriptTokenScriptFails96=== CONT TestDoServerRequestAttachesToken97=== CONT TestResolveStorePath98=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess99=== CONT TestRateLimiterFeedback100=== RUN TestRateLimiterFeedback/429_enables_limiter101=== PAUSE TestRateLimiterFeedback/429_enables_limiter102=== RUN TestRateLimiterFeedback/503_enables_limiter103=== PAUSE TestRateLimiterFeedback/503_enables_limiter104=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter105=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter106=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter107=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter108=== CONT TestClientSignaturesByStorePath109--- PASS: TestClientSignaturesByStorePath (0.00s)110=== CONT TestStreamPushReportsSignatures111=== CONT TestPathInfoCACompatibility112=== RUN TestPathInfoCACompatibility/null_ca_field113=== PAUSE TestPathInfoCACompatibility/null_ca_field114=== RUN TestPathInfoCACompatibility/old_string_format_-_text115=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text116=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive117=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive118=== RUN TestPathInfoCACompatibility/new_structured_format_-_text119=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text120=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method121=== CONT TestParsePathInfoJSONMultiplePaths122=== CONT TestParsePathInfoJSON123=== CONT TestPathInfoHashCompatibility124=== CONT TestGetStorePathHash125=== CONT TestConvertHashToNix32126=== CONT TestEncodeNixBase32WithRealHash127=== CONT TestEncodeNixBase32128=== CONT TestDumpPathWriterError1292026/09/23 09:41:03 WARN Rate limiter enabled after throttle name=server-test rate=5130=== CONT TestDumpPathSingleFile131=== CONT TestDumpPathMatchesNix132=== CONT TestUploadMultipart_SupersededByPeer133=== CONT TestPartSizeForNAR134=== CONT TestDoWithRetry_BodyReplayedViaGetBody135=== CONT TestUploadMultipart_PartsInParallel136=== CONT TestFilterOversizedClosures137=== CONT TestSetClientTLS138=== CONT TestCaseHackSuffix139=== CONT TestSetClientTLSDoesNotMutateDefaultTransport140=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method141=== RUN TestUploadMultipart_SupersededByPeer/exists142=== CONT TestRegisterUploadedObjectReusesConnections143--- PASS: TestScriptTokenScriptFails (0.00s)144=== CONT TestStreamPushRequestLine145=== RUN TestEncodeNixBase32/test_string_hash146--- PASS: TestResolveStorePath (0.00s)147=== CONT TestStreamPushGivesUpOnDeadServer148=== RUN TestPartSizeForNAR/zero_stays_at_minimum149=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum1502026/09/23 09:41:03 ERROR Upload failed error="connection refused" count=201512026/09/23 09:41:03 ERROR Upload failed error=boom count=1152=== PAUSE TestUploadMultipart_SupersededByPeer/exists153=== RUN TestUploadMultipart_SupersededByPeer/missing154--- PASS: TestStreamPushReportsSignatures (0.00s)1552026/09/23 09:41:03 ERROR Server seems unavailable, giving up on batch untried=17156=== RUN TestFilterOversizedClosures/no_limit_keeps_everything157=== CONT TestFileTokenEmpty158--- PASS: TestFileTokenEmpty (0.00s)159=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything160=== PAUSE TestUploadMultipart_SupersededByPeer/missing161=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)162=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths163=== RUN TestParsePathInfoJSON/Nix_format164=== CONT TestScriptTokenCachesUntilRefresh165=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths166=== PAUSE TestParsePathInfoJSON/Nix_format167=== RUN TestGetStorePathHash/valid_store_path1682026/09/23 09:41:03 WARN Rate limiter enabled after throttle name=server-test rate=5169=== PAUSE TestEncodeNixBase32/test_string_hash170=== CONT TestStreamPushIsolatesFailures1712026/09/23 09:41:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45723172--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)173=== PAUSE TestGetStorePathHash/valid_store_path174=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1752026/09/23 09:41:03 ERROR Upload failed error=boom count=1176--- PASS: TestDoServerRequestAttachesToken (0.03s)177=== CONT TestScriptTokenNoExpiryRerunsEveryCall178=== RUN TestConvertHashToNix32/SRI_format_to_Nix32179=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32180=== RUN TestConvertHashToNix32/already_Nix32_format181=== CONT TestStreamPushBatchesUnderLoad1822026/09/23 09:41:03 WARN Rate limiter backed off name=server-test rate=5183=== RUN TestParsePathInfoJSON/Lix_format1842026/09/23 09:41:03 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45723185=== PAUSE TestParsePathInfoJSON/Lix_format186=== RUN TestParsePathInfoJSON/empty_input187=== RUN TestGetStorePathHash/basename_without_hyphen_should_error188=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error189=== RUN TestSetClientTLS/rejects_connection_without_client_cert190=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths191=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths192=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon193=== PAUSE TestParsePathInfoJSON/empty_input194=== PAUSE TestConvertHashToNix32/already_Nix32_format195=== RUN TestPartSizeForNAR/small_stays_at_minimum196=== PAUSE TestPartSizeForNAR/small_stays_at_minimum197=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum198=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum199=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts200=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts201=== RUN TestPartSizeForNAR/1_TiB202=== PAUSE TestPartSizeForNAR/1_TiB203=== RUN TestPartSizeForNAR/5_TiB_S3_max_object204=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object205=== RUN TestPartSizeForNAR/capped_at_5_GiB206=== PAUSE TestPartSizeForNAR/capped_at_5_GiB207=== RUN TestEncodeNixBase32/empty_input208=== CONT TestStaticToken209=== CONT TestFileTokenMissing210=== PAUSE TestEncodeNixBase32/empty_input211=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error212=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error213=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert214=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA215=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA216=== RUN TestSetClientTLS/preserves_debug_logging_transport217=== PAUSE TestSetClientTLS/preserves_debug_logging_transport218=== CONT TestStreamPushReportsEveryPath219=== CONT TestSetClientTLSErrors220=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon221=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI222=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI223=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512224=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512225--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)226--- PASS: TestStaticToken (0.00s)227=== CONT TestScriptTokenBadJSON228--- PASS: TestStreamPushReportsEveryPath (0.00s)229=== CONT TestShellSplit230--- PASS: TestFileTokenMissing (0.00s)231--- PASS: TestShellSplit (0.00s)232=== CONT TestScriptTokenEmptyToken233=== CONT TestFileTokenReadsAndCaches234--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.04s)235=== CONT TestRateLimiterFeedback/429_enables_limiter236=== CONT TestScriptTokenEmptyCommand237--- PASS: TestEncodeNixBase32WithRealHash (0.03s)238--- PASS: TestScriptTokenEmptyCommand (0.00s)239=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter240=== RUN TestSetClientTLSErrors/missing_cert_file241=== PAUSE TestSetClientTLSErrors/missing_cert_file242=== RUN TestSetClientTLSErrors/missing_key_file243=== PAUSE TestSetClientTLSErrors/missing_key_file244=== RUN TestSetClientTLSErrors/missing_ca_file245=== PAUSE TestSetClientTLSErrors/missing_ca_file246=== RUN TestSetClientTLSErrors/invalid_ca_file247=== PAUSE TestSetClientTLSErrors/invalid_ca_file248=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2492026/09/23 09:41:03 WARN Rate limiter enabled after throttle name=server-test rate=52502026/09/23 09:41:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:32897251--- PASS: TestFileTokenReadsAndCaches (0.00s)252=== CONT TestPathInfoCACompatibility/null_ca_field253=== CONT TestRateLimiterFeedback/503_enables_limiter254=== RUN TestConvertHashToNix32/invalid_format255=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped256=== PAUSE TestConvertHashToNix32/invalid_format257=== CONT TestShellSplitErrors258--- PASS: TestShellSplitErrors (0.00s)259=== CONT TestPathInfoCACompatibility/new_structured_format_-_text260=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2612026/09/23 09:41:03 WARN Rate limiter backed off name=server-test rate=5262=== CONT TestUploadMultipart_SupersededByPeer/exists2632026/09/23 09:41:03 ERROR Upload failed error="bad path" count=3264--- PASS: TestStreamPushIsolatesFailures (0.00s)265=== CONT TestUploadMultipart_SupersededByPeer/missing266--- PASS: TestCaseHackSuffix (0.04s)2672026/09/23 09:41:03 WARN Rate limiter enabled after throttle name=server-test rate=5268=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2692026/09/23 09:41:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:36321270=== CONT TestPartSizeForNAR/zero_stays_at_minimum271=== CONT TestPartSizeForNAR/1_TiB272=== RUN TestFilterOversizedClosures/all_closures_skipped273=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts274=== PAUSE TestFilterOversizedClosures/all_closures_skipped275=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2762026/09/23 09:41:03 WARN Rate limiter backed off name=server-test rate=5277=== CONT TestPartSizeForNAR/capped_at_5_GiB278=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive279=== CONT TestEncodeNixBase32/test_string_hash280=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error281=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error282=== CONT TestPathInfoCACompatibility/old_string_format_-_text283=== CONT TestSetClientTLS/rejects_connection_without_client_cert284=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method285--- PASS: TestScriptTokenBadJSON (0.01s)286=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)287=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI288=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon289=== CONT TestSetClientTLSErrors/missing_cert_file290=== CONT TestSetClientTLSErrors/missing_key_file291=== CONT TestSetClientTLSErrors/invalid_ca_file292=== CONT TestSetClientTLSErrors/missing_ca_file293=== CONT TestConvertHashToNix32/SRI_format_to_Nix32294=== CONT TestConvertHashToNix32/invalid_format295=== CONT TestConvertHashToNix32/already_Nix32_format296=== CONT TestFilterOversizedClosures/no_limit_keeps_everything297=== CONT TestFilterOversizedClosures/all_closures_skipped298=== CONT TestGetStorePathHash/valid_store_path2992026/09/23 09:41:03 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=50300=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error301=== CONT TestGetStorePathHash/basename_without_hyphen_should_error302=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error303=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512304=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum305=== CONT TestPartSizeForNAR/small_stays_at_minimum306=== CONT TestPartSizeForNAR/5_TiB_S3_max_object307=== CONT TestEncodeNixBase32/empty_input308=== RUN TestParsePathInfoJSON/whitespace_only309=== PAUSE TestParsePathInfoJSON/whitespace_only310=== RUN TestParsePathInfoJSON/invalid_JSON311=== PAUSE TestParsePathInfoJSON/invalid_JSON312=== CONT TestParsePathInfoJSON/Nix_format313--- PASS: TestPathInfoCACompatibility (0.00s)314 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)315 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)316 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)317 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)318 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)319--- PASS: TestRateLimiterFeedback (0.00s)320 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)321 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)322 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)323 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)324=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3252026/09/23 09:41:03 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=2000326=== CONT TestSetClientTLS/preserves_debug_logging_transport327=== CONT TestParsePathInfoJSON/empty_input328=== CONT TestParsePathInfoJSON/invalid_JSON329=== CONT TestParsePathInfoJSON/whitespace_only330=== CONT TestParsePathInfoJSON/Lix_format331=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA332--- PASS: TestScriptTokenEmptyToken (0.01s)333--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)334--- PASS: TestConvertHashToNix32 (0.03s)335 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)336 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)337 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)338--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)339--- PASS: TestFilterOversizedClosures (0.04s)340 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)341 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)342 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)343--- PASS: TestGetStorePathHash (0.04s)344 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)345 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)346 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)347 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)348--- PASS: TestPathInfoHashCompatibility (0.03s)349 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)350 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)351 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)352 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)353--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)354 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.01s)355 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)356--- PASS: TestPartSizeForNAR (0.03s)357 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)358 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)359 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)360 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)361 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)362 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)364--- PASS: TestEncodeNixBase32 (0.03s)365 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)366 --- PASS: TestEncodeNixBase32/empty_input (0.00s)367--- PASS: TestParsePathInfoJSON (0.04s)368 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)369 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)370 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)371 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)372 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)373--- PASS: TestSetClientTLSErrors (0.00s)374 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)375 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)376 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)378--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)379 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)380 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)381--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)3822026/09/23 09:41:04 http: TLS handshake error from 127.0.0.1:41528: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.03s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestStreamPushRequestLine (0.06s)388--- PASS: TestDumpPathSingleFile (0.07s)389--- PASS: TestDumpPathWriterError (0.07s)390--- PASS: TestDumpPathMatchesNix (0.12s)391--- PASS: TestStreamPushBatchesUnderLoad (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres1121856168/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/postgres1121856168/data -l logfile start422423/build/postgres1121856168:5432 - no response4242026-09-23 09:41:05.807 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-23 09:41:05.807 UTC [129] LOG: listening on Unix socket "/build/postgres1121856168/.s.PGSQL.5432"4262026-09-23 09:41:05.812 UTC [136] LOG: database system was shut down at 2026-09-23 09:41:05 UTC4272026-09-23 09:41:05.816 UTC [129] LOG: database system is ready to accept connections428/build/postgres1121856168:5432 - accepting connections429{"timestamp":"2026-09-23T09:41:06.01034351Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"9bc3c26f-2275-41b8-b70c-923e43c1d3d4","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(194)"}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 09:41:06.220 UTC [371] ERROR: relation "goose_db_version" does not exist at character 364682026-09-23 09:41:06.220 UTC [371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4692026/09/23 09:41:06 OK 20241026095416_initial_model.sql (11.01ms)4702026/09/23 09:41:06 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)4712026/09/23 09:41:06 OK 20251218171726_add_pins.sql (3.1ms)4722026/09/23 09:41:06 OK 20260628120000_add_object_size_and_stats.sql (2.71ms)4732026/09/23 09:41:06 OK 20260905000000_add_claims.sql (3.27ms)4742026/09/23 09:41:06 OK 20260920000000_drop_claims.sql (1.89ms)4752026/09/23 09:41:06 goose: successfully migrated database to version: 202609200000004762026/09/23 09:41:06 OK 1_commit_pending_closure.sql (1.96ms)4772026/09/23 09:41:06 OK 2_object_stats_trigger.sql (853.15µs)4782026/09/23 09:41:06 goose: up to current file version: 24792026/09/23 09:41:06 INFO lead: acquired remote=192.0.2.1:12344802026/09/23 09:41:06 INFO lead: released remote=192.0.2.1:12344812026/09/23 09:41:06 INFO lead: acquired remote=192.0.2.1:12344822026/09/23 09:41:06 INFO lead: released remote=192.0.2.1:1234483--- PASS: TestLeadIncumbentWinsAfterRestart (0.82s)484=== RUN TestLeadEndsOnShutdown485=== PAUSE TestLeadEndsOnShutdown486=== RUN TestGCAdvisoryLockBlocksConcurrentRun4872026-09-23 09:41:06.993 UTC [381] ERROR: relation "goose_db_version" does not exist at character 364882026-09-23 09:41:06.993 UTC [381] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4892026/09/23 09:41:07 OK 20241026095416_initial_model.sql (9.4ms)4902026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)4912026/09/23 09:41:07 OK 20251218171726_add_pins.sql (3.36ms)4922026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (2.52ms)4932026/09/23 09:41:07 OK 20260905000000_add_claims.sql (2.78ms)4942026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (2.09ms)4952026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000004962026/09/23 09:41:07 OK 1_commit_pending_closure.sql (1.76ms)4972026/09/23 09:41:07 OK 2_object_stats_trigger.sql (747.63µs)4982026/09/23 09:41:07 goose: up to current file version: 2499--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)500=== RUN TestGCBugBareHashReferences501=== PAUSE TestGCBugBareHashReferences502=== RUN TestGCMetrics503=== PAUSE TestGCMetrics504=== RUN TestGCTaskStore_StartNew505=== PAUSE TestGCTaskStore_StartNew506=== RUN TestGCTaskStore_DeduplicateSameParams507=== PAUSE TestGCTaskStore_DeduplicateSameParams508=== RUN TestGCTaskStore_ConflictDifferentParams509=== PAUSE TestGCTaskStore_ConflictDifferentParams510=== RUN TestGCTaskStore_GetEmpty511=== PAUSE TestGCTaskStore_GetEmpty512=== RUN TestGCTaskStore_GetReturnsLatest513=== PAUSE TestGCTaskStore_GetReturnsLatest514=== RUN TestGCTaskStore_CompletedAllowsNewTask515=== PAUSE TestGCTaskStore_CompletedAllowsNewTask516=== RUN TestGCTaskStore_PhaseUpdates517=== PAUSE TestGCTaskStore_PhaseUpdates518=== RUN TestGCTaskStore_Fail519=== PAUSE TestGCTaskStore_Fail520=== RUN TestGracefulShutdownDrainsInflight521=== PAUSE TestGracefulShutdownDrainsInflight522=== RUN TestService_healthCheckHandler523=== PAUSE TestService_healthCheckHandler524=== RUN TestService_readinessHandler525=== PAUSE TestService_readinessHandler526=== RUN TestGenerateLandingPage527=== PAUSE TestGenerateLandingPage528=== RUN TestCacheConfigHandlerMaxNarSize529=== PAUSE TestCacheConfigHandlerMaxNarSize530=== RUN TestCreatePendingClosureRejectsOversizedNAR531=== PAUSE TestCreatePendingClosureRejectsOversizedNAR532=== RUN TestNARDeduplicationMetadataUploadBug533=== PAUSE TestNARDeduplicationMetadataUploadBug534=== RUN TestMetricsInventory535=== PAUSE TestMetricsInventory536=== RUN TestService_NativeMTLS537=== PAUSE TestService_NativeMTLS538=== RUN TestServerTLSConfig539=== PAUSE TestServerTLSConfig540=== RUN TestMultipartCleanup541=== PAUSE TestMultipartCleanup542=== RUN TestObjectStatsTrigger543=== PAUSE TestObjectStatsTrigger544=== RUN TestOrphanedObjectsGC545=== PAUSE TestOrphanedObjectsGC546=== RUN TestOrphanedObjectsGCStressTest547=== PAUSE TestOrphanedObjectsGCStressTest548=== RUN TestResurrectedObjectNotDeleted549=== PAUSE TestResurrectedObjectNotDeleted550=== RUN TestCreatePin_ReservedPins551=== PAUSE TestCreatePin_ReservedPins552=== RUN TestParseSingleRange553=== PAUSE TestParseSingleRange554=== RUN TestProxyHeadersOnlyTrustedOnSocket555=== PAUSE TestProxyHeadersOnlyTrustedOnSocket556=== RUN TestIsValidCachePath557=== PAUSE TestIsValidCachePath558=== RUN TestReadProxyNarinfo559=== PAUSE TestReadProxyNarinfo560=== RUN TestReadProxyNarinfoAlreadyDecompressed561=== PAUSE TestReadProxyNarinfoAlreadyDecompressed562=== RUN TestReadProxyNarStreaming563=== PAUSE TestReadProxyNarStreaming564=== RUN TestReadProxy404565=== PAUSE TestReadProxy404566=== RUN TestReadProxyInvalidPath567=== PAUSE TestReadProxyInvalidPath568=== RUN TestReadProxyHead569=== PAUSE TestReadProxyHead570=== RUN TestReadProxyConditionalGet571=== PAUSE TestReadProxyConditionalGet572=== RUN TestReadProxyRootRedirectsToIndexHTML573=== PAUSE TestReadProxyRootRedirectsToIndexHTML574=== RUN TestReadProxyDisabled575=== PAUSE TestReadProxyDisabled576=== RUN TestReadRedirectNar577=== PAUSE TestReadRedirectNar578=== RUN TestReadRedirectKeepsNarinfoProxied579=== PAUSE TestReadRedirectKeepsNarinfoProxied580=== RUN TestReadProxyRangeRequest581=== PAUSE TestReadProxyRangeRequest582=== RUN TestReadRedirectUsesPublicS3URL583=== PAUSE TestReadRedirectUsesPublicS3URL584=== RUN TestRedundantMultipartUpload585=== PAUSE TestRedundantMultipartUpload586=== RUN TestCompleteMultipartUpload_ErrorButObjectExists587=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists588=== RUN TestCompletedNarNotReofferedAcrossClosures589=== PAUSE TestCompletedNarNotReofferedAcrossClosures590=== RUN TestPresignedUploadRegisteredBeforeCommit591=== PAUSE TestPresignedUploadRegisteredBeforeCommit592=== RUN TestService_Rustfstest593=== PAUSE TestService_Rustfstest594=== RUN TestParseSize595=== PAUSE TestParseSize596=== RUN TestSkippedUploadsHandler597=== PAUSE TestSkippedUploadsHandler598=== RUN TestSystemdListenerNotActivated599--- PASS: TestSystemdListenerNotActivated (0.00s)600=== RUN TestWatchdogBeatsWhenHealthy601--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)602=== RUN TestWatchdogSkipsWhenUnhealthy6032026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6042026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6052026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6062026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6072026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6082026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6092026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6102026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6112026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6122026/09/23 09:41:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"613--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)614=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle615=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle616=== RUN TestProxyWriteTimeout617=== PAUSE TestProxyWriteTimeout618=== RUN TestIsValidUploadKey619=== PAUSE TestIsValidUploadKey620=== RUN TestUploadHandlersRejectInvalidKeys621=== PAUSE TestUploadHandlersRejectInvalidKeys622=== RUN TestUploadHandlersRejectOversizedBody623=== PAUSE TestUploadHandlersRejectOversizedBody624=== RUN TestService_cleanupPendingClosuresHandler625=== PAUSE TestService_cleanupPendingClosuresHandler626=== RUN TestService_createPendingClosureHandler627=== PAUSE TestService_createPendingClosureHandler628=== RUN TestService_verifyS3Integrity629=== PAUSE TestService_verifyS3Integrity630=== RUN TestCompleteMultipartUnregistered631=== PAUSE TestCompleteMultipartUnregistered632=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT633=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT634=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT635=== CONT TestService_AuthMiddleware636=== CONT TestCompleteMultipartUnregistered637=== CONT TestService_verifyS3Integrity638=== CONT TestService_createPendingClosureHandler639=== CONT TestService_cleanupPendingClosuresHandler640=== CONT TestMetricsInventory641=== CONT TestNARDeduplicationMetadataUploadBug642=== CONT TestCreatePendingClosureRejectsOversizedNAR643=== CONT TestCacheConfigHandlerMaxNarSize644=== CONT TestGenerateLandingPage6452026/09/23 09:41:07 INFO Received uploads request method=POST path=/api/pending_closures646--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)647=== CONT TestGCTaskStore_GetEmpty648=== CONT TestService_readinessHandler649=== CONT TestService_NativeMTLS650=== CONT TestService_healthCheckHandler651=== CONT TestUploadHandlersRejectOversizedBody652=== CONT TestGracefulShutdownDrainsInflight653=== CONT TestUploadHandlersRejectInvalidKeys654=== CONT TestGCTaskStore_Fail655=== CONT TestGCTaskStore_PhaseUpdates656=== CONT TestIsValidUploadKey657=== CONT TestGCTaskStore_CompletedAllowsNewTask658=== CONT TestProxyWriteTimeout659=== CONT TestGCTaskStore_GetReturnsLatest660=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle661--- PASS: TestGCTaskStore_GetEmpty (0.00s)662=== CONT TestSkippedUploadsHandler663--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)664=== CONT TestGCTaskStore_ConflictDifferentParams665--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)666=== CONT TestParseSize667--- PASS: TestParseSize (0.00s)668=== CONT TestGCTaskStore_DeduplicateSameParams669--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)670=== CONT TestService_Rustfstest6712026/09/23 09:41:07 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000672=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info673=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info674--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)675=== RUN TestIsValidUploadKey/narinfo676--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)677=== PAUSE TestIsValidUploadKey/narinfo678=== RUN TestIsValidUploadKey/nar_zst679=== CONT TestGCMetrics6802026/09/23 09:41:07 INFO Starting HTTP server address=127.0.0.1:40533681=== CONT TestCompletedNarNotReofferedAcrossClosures682=== CONT TestGCTaskStore_StartNew683=== CONT TestClientCADerivations684=== CONT TestPresignedUploadRegisteredBeforeCommit685=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal686--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)687--- PASS: TestGCTaskStore_Fail (0.00s)688--- PASS: TestGCTaskStore_StartNew (0.00s)689=== PAUSE TestIsValidUploadKey/nar_zst690=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal6912026/09/23 09:41:07 INFO Shutdown signal received, draining in-flight requests timeout=10s692=== RUN TestIsValidUploadKey/nar_xz693=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key694=== RUN TestProxyWriteTimeout/narinfo695--- PASS: TestSkippedUploadsHandler (0.01s)696=== PAUSE TestIsValidUploadKey/nar_xz697=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key698=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key699=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key700=== RUN TestIsValidUploadKey/nar_plain701=== PAUSE TestIsValidUploadKey/nar_plain702=== PAUSE TestProxyWriteTimeout/narinfo703=== CONT TestCompleteMultipartUpload_ErrorButObjectExists704=== CONT TestCacheStatsHandler705=== RUN TestIsValidUploadKey/listing706=== RUN TestProxyWriteTimeout/1_GiB_nar707=== PAUSE TestIsValidUploadKey/listing708=== PAUSE TestProxyWriteTimeout/1_GiB_nar709=== RUN TestProxyWriteTimeout/10_GiB_nar710=== PAUSE TestProxyWriteTimeout/10_GiB_nar711=== RUN TestProxyWriteTimeout/unknown_size712=== RUN TestIsValidUploadKey/build_log713=== PAUSE TestIsValidUploadKey/build_log714--- PASS: TestGracefulShutdownDrainsInflight (0.09s)715=== CONT TestRedundantMultipartUpload716=== PAUSE TestProxyWriteTimeout/unknown_size717=== CONT TestCacheConfigHandler718=== RUN TestCacheConfigHandler/full_config,_no_issuer719=== PAUSE TestCacheConfigHandler/full_config,_no_issuer720=== RUN TestCacheConfigHandler/no_cache_url_configured721=== RUN TestIsValidUploadKey/build_log_home-manager_file722=== PAUSE TestIsValidUploadKey/build_log_home-manager_file723=== PAUSE TestCacheConfigHandler/no_cache_url_configured724=== RUN TestIsValidUploadKey/build_log_plus_in_name725=== PAUSE TestIsValidUploadKey/build_log_plus_in_name726=== RUN TestIsValidUploadKey/build_log_question_mark727=== RUN TestCacheConfigHandler/no_signing_keys728=== PAUSE TestIsValidUploadKey/build_log_question_mark729=== RUN TestIsValidUploadKey/build_log_equals730=== PAUSE TestIsValidUploadKey/build_log_equals731=== RUN TestIsValidUploadKey/realisation732=== PAUSE TestIsValidUploadKey/realisation733=== PAUSE TestCacheConfigHandler/no_signing_keys734=== RUN TestIsValidUploadKey/realisation_plus_in_output735=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator736=== PAUSE TestIsValidUploadKey/realisation_plus_in_output737=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator738=== CONT TestReadRedirectUsesPublicS3URL739=== RUN TestIsValidUploadKey/nix-cache-info740=== PAUSE TestIsValidUploadKey/nix-cache-info741=== RUN TestIsValidUploadKey/index.html742=== PAUSE TestIsValidUploadKey/index.html743=== RUN TestIsValidUploadKey/narinfo_key,_nar_type744=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type745=== RUN TestIsValidUploadKey/nar_key,_narinfo_type746=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type747=== RUN TestIsValidUploadKey/listing_key,_narinfo_type748=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type749=== RUN TestIsValidUploadKey/traversal750=== PAUSE TestIsValidUploadKey/traversal751=== RUN TestIsValidUploadKey/traversal_nar752=== PAUSE TestIsValidUploadKey/traversal_nar753=== RUN TestIsValidUploadKey/absolute754=== PAUSE TestIsValidUploadKey/absolute755=== RUN TestIsValidUploadKey/empty_key756=== PAUSE TestIsValidUploadKey/empty_key757=== RUN TestIsValidUploadKey/unknown_type758=== PAUSE TestIsValidUploadKey/unknown_type759--- PASS: TestGenerateLandingPage (0.09s)760=== CONT TestService_ReadScope_PublicByDefault761=== CONT TestReadProxyRangeRequest7622026-09-23 09:41:07.374 UTC [438] ERROR: relation "goose_db_version" does not exist at character 367632026-09-23 09:41:07.374 UTC [438] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC764=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure765=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure766=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart767=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart768=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts769=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts770=== CONT TestService_RequireScope_OIDC7712026-09-23 09:41:07.454 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367722026-09-23 09:41:07.454 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026-09-23 09:41:07.454 UTC [450] ERROR: relation "goose_db_version" does not exist at character 367742026-09-23 09:41:07.454 UTC [450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7752026-09-23 09:41:07.455 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367762026-09-23 09:41:07.455 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026-09-23 09:41:07.526 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367782026-09-23 09:41:07.526 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026-09-23 09:41:07.581 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367802026-09-23 09:41:07.581 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026/09/23 09:41:07 OK 20241026095416_initial_model.sql (149.42ms)7822026-09-23 09:41:07.602 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367832026-09-23 09:41:07.602 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (4.98ms)7852026/09/23 09:41:07 OK 20241026095416_initial_model.sql (75.17ms)7862026/09/23 09:41:07 OK 20241026095416_initial_model.sql (76.57ms)7872026/09/23 09:41:07 OK 20251218171726_add_pins.sql (18.96ms)7882026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (14.22ms)7892026/09/23 09:41:07 OK 20241026095416_initial_model.sql (86.08ms)7902026/09/23 09:41:07 OK 20241026095416_initial_model.sql (24.99ms)7912026/09/23 09:41:07 OK 20241026095416_initial_model.sql (83.83ms)7922026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (13.57ms)7932026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.15ms)7942026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (4.8ms)7952026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (4.62ms)7962026/09/23 09:41:07 OK 20251218171726_add_pins.sql (8.97ms)7972026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (9.51ms)7982026/09/23 09:41:07 OK 20251218171726_add_pins.sql (8.77ms)7992026/09/23 09:41:07 OK 20251218171726_add_pins.sql (7.37ms)8002026/09/23 09:41:07 OK 20241026095416_initial_model.sql (26.2ms)8012026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (6.03ms)8022026/09/23 09:41:07 OK 20251218171726_add_pins.sql (8.26ms)8032026/09/23 09:41:07 OK 20251218171726_add_pins.sql (8.39ms)8042026-09-23 09:41:07.640 UTC [455] ERROR: relation "goose_db_version" does not exist at character 368052026-09-23 09:41:07.640 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8062026/09/23 09:41:07 OK 20260905000000_add_claims.sql (7.8ms)8072026-09-23 09:41:07.641 UTC [456] ERROR: relation "goose_db_version" does not exist at character 368082026-09-23 09:41:07.641 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8092026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (7.36ms)8102026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (4.21ms)8112026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (7.34ms)8122026-09-23 09:41:07.643 UTC [457] ERROR: relation "goose_db_version" does not exist at character 368132026-09-23 09:41:07.643 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026-09-23 09:41:07.644 UTC [458] ERROR: relation "goose_db_version" does not exist at character 368152026-09-23 09:41:07.644 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (5.49ms)8172026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000008182026/09/23 09:41:07 OK 20260905000000_add_claims.sql (7.64ms)8192026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (8.84ms)8202026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (8.77ms)8212026/09/23 09:41:07 OK 20251218171726_add_pins.sql (6.45ms)8222026/09/23 09:41:07 OK 20260905000000_add_claims.sql (6.7ms)8232026/09/23 09:41:07 OK 20260905000000_add_claims.sql (8.09ms)8242026/09/23 09:41:07 OK 1_commit_pending_closure.sql (5.4ms)8252026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (5.49ms)8262026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000008272026-09-23 09:41:07.655 UTC [459] ERROR: relation "goose_db_version" does not exist at character 368282026-09-23 09:41:07.655 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026-09-23 09:41:07.655 UTC [460] ERROR: relation "goose_db_version" does not exist at character 368302026-09-23 09:41:07.655 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-09-23 09:41:07.658 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368322026-09-23 09:41:07.658 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026-09-23 09:41:07.659 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368342026-09-23 09:41:07.659 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026-09-23 09:41:07.660 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368362026-09-23 09:41:07.660 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (15.19ms)8382026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000008392026-09-23 09:41:07.666 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368402026-09-23 09:41:07.666 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8412026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (17.74ms)8422026/09/23 09:41:07 OK 1_commit_pending_closure.sql (14.76ms)8432026/09/23 09:41:07 OK 20260905000000_add_claims.sql (19.03ms)8442026/09/23 09:41:07 OK 20260905000000_add_claims.sql (18.99ms)8452026/09/23 09:41:07 OK 20241026095416_initial_model.sql (16.77ms)8462026/09/23 09:41:07 OK 2_object_stats_trigger.sql (15.05ms)8472026/09/23 09:41:07 goose: up to current file version: 28482026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (17.85ms)8492026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000008502026/09/23 09:41:07 OK 20241026095416_initial_model.sql (14.97ms)8512026/09/23 09:41:07 OK 20241026095416_initial_model.sql (15.39ms)8522026/09/23 09:41:07 OK 20241026095416_initial_model.sql (15.37ms)8532026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.34ms)8542026/09/23 09:41:07 goose: up to current file version: 28552026/09/23 09:41:07 OK 1_commit_pending_closure.sql (4.68ms)8562026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)8572026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)8582026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (4.59ms)8592026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000008602026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)8612026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)8622026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (5.75ms)8632026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000008642026/09/23 09:41:07 OK 20260905000000_add_claims.sql (6.55ms)8652026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.96ms)8662026/09/23 09:41:07 goose: up to current file version: 28672026/09/23 09:41:07 OK 1_commit_pending_closure.sql (5.12ms)8682026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.47ms)8692026/09/23 09:41:07 goose: up to current file version: 28702026/09/23 09:41:07 OK 20251218171726_add_pins.sql (6.77ms)8712026/09/23 09:41:07 OK 20251218171726_add_pins.sql (5.84ms)8722026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.86ms)8732026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.81ms)8742026/09/23 09:41:07 OK 1_commit_pending_closure.sql (5.63ms)8752026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (5.01ms)8762026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000008772026/09/23 09:41:07 OK 1_commit_pending_closure.sql (5.65ms)8782026-09-23 09:41:07.679 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368792026-09-23 09:41:07.679 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8802026/09/23 09:41:07 OK 20241026095416_initial_model.sql (12.37ms)8812026/09/23 09:41:07 OK 20241026095416_initial_model.sql (13.73ms)8822026/09/23 09:41:07 OK 20241026095416_initial_model.sql (12.4ms)8832026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.71ms)8842026/09/23 09:41:07 goose: up to current file version: 28852026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)8862026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.87ms)8872026/09/23 09:41:07 goose: up to current file version: 28882026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)8892026/09/23 09:41:07 OK 20241026095416_initial_model.sql (14.91ms)8902026-09-23 09:41:07.683 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368912026-09-23 09:41:07.683 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8922026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (5.9ms)8932026/09/23 09:41:07 OK 1_commit_pending_closure.sql (4.98ms)8942026/09/23 09:41:07 OK 20241026095416_initial_model.sql (14.89ms)8952026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (6.18ms)8962026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)8972026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.47ms)8982026-09-23 09:41:07.684 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368992026-09-23 09:41:07.684 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9002026-09-23 09:41:07.685 UTC [468] ERROR: relation "goose_db_version" does not exist at character 369012026-09-23 09:41:07.685 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9022026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)9032026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)9042026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.38ms)9052026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.28ms)9062026/09/23 09:41:07 goose: up to current file version: 29072026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.27ms)9082026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.15ms)9092026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.7ms)9102026/09/23 09:41:07 OK 20241026095416_initial_model.sql (14.14ms)9112026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.88ms)9122026/09/23 09:41:07 OK 20260905000000_add_claims.sql (5.58ms)9132026/09/23 09:41:07 OK 20251218171726_add_pins.sql (5.13ms)9142026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.67ms)9152026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (2.85ms)9162026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009172026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (3.58ms)9182026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009192026/09/23 09:41:07 OK 20251218171726_add_pins.sql (5.59ms)9202026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.4ms)9212026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.22ms)9222026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.87ms)9232026/09/23 09:41:07 OK 1_commit_pending_closure.sql (1.8ms)9242026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (4.47ms)9252026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009262026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (3.61ms)9272026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009282026/09/23 09:41:07 OK 2_object_stats_trigger.sql (1.9ms)9292026/09/23 09:41:07 goose: up to current file version: 29302026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.63ms)9312026/09/23 09:41:07 goose: up to current file version: 29322026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (5.79ms)9332026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (5.93ms)9342026-09-23 09:41:07.696 UTC [469] ERROR: relation "goose_db_version" does not exist at character 369352026-09-23 09:41:07.696 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9362026/09/23 09:41:07 OK 1_commit_pending_closure.sql (3.77ms)9372026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)9382026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.83ms)9392026/09/23 09:41:07 OK 20241026095416_initial_model.sql (10.38ms)9402026/09/23 09:41:07 OK 1_commit_pending_closure.sql (3.48ms)9412026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)9422026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (7.05ms)9432026-09-23 09:41:07.697 UTC [470] ERROR: relation "goose_db_version" does not exist at character 369442026-09-23 09:41:07.697 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9452026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.23ms)9462026/09/23 09:41:07 goose: up to current file version: 29472026/09/23 09:41:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9482026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.22ms)9492026/09/23 09:41:07 goose: up to current file version: 29502026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.63ms)9512026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)9522026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.62ms)9532026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.63ms)9542026/09/23 09:41:07 OK 20260905000000_add_claims.sql (5.25ms)9552026/09/23 09:41:07 OK 20260905000000_add_claims.sql (5.21ms)9562026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)9572026/09/23 09:41:07 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst958--- PASS: TestCompleteMultipartUnregistered (0.43s)959=== CONT TestReadRedirectKeepsNarinfoProxied9602026/09/23 09:41:07 OK 20241026095416_initial_model.sql (13.07ms)9612026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (3.61ms)9622026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009632026/09/23 09:41:07 OK 20251218171726_add_pins.sql (3.88ms)9642026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (3.46ms)9652026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009662026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (4.75ms)9672026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009682026/09/23 09:41:07 OK 20241026095416_initial_model.sql (12.34ms)9692026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (3.85ms)9702026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009712026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (4.01ms)9722026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009732026/09/23 09:41:07 OK 20241026095416_initial_model.sql (13.65ms)9742026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (3.73ms)9752026/09/23 09:41:07 OK 20260905000000_add_claims.sql (5.2ms)9762026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.5ms)9772026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)9782026/09/23 09:41:07 OK 1_commit_pending_closure.sql (3.44ms)9792026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.67ms)9802026/09/23 09:41:07 OK 1_commit_pending_closure.sql (1.68ms)9812026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)9822026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.05ms)9832026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)9842026/09/23 09:41:07 OK 2_object_stats_trigger.sql (1.81ms)9852026/09/23 09:41:07 goose: up to current file version: 29862026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.64ms)9872026/09/23 09:41:07 goose: up to current file version: 29882026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.33ms)9892026/09/23 09:41:07 goose: up to current file version: 29902026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.21ms)9912026/09/23 09:41:07 goose: up to current file version: 29922026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.17ms)9932026/09/23 09:41:07 goose: up to current file version: 29942026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.02ms)9952026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (4.28ms)9962026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000009972026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.72ms)9982026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.63ms)9992026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.9ms)10002026/09/23 09:41:07 OK 1_commit_pending_closure.sql (3.53ms)10012026/09/23 09:41:07 OK 20241026095416_initial_model.sql (11.68ms)10022026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)10032026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (2.89ms)10042026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000010052026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)10062026/09/23 09:41:07 OK 20241026095416_initial_model.sql (12.94ms)10072026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)10082026/09/23 09:41:07 OK 2_object_stats_trigger.sql (1.42ms)10092026/09/23 09:41:07 goose: up to current file version: 210102026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)10112026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)10122026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.13ms)10132026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.32ms)10142026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.05ms)10152026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.46ms)10162026/09/23 09:41:07 goose: up to current file version: 210172026/09/23 09:41:07 OK 20260905000000_add_claims.sql (3.79ms)10182026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.23ms)10192026/09/23 09:41:07 OK 20251218171726_add_pins.sql (3.4ms)10202026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (2.71ms)10212026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000010222026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (1.99ms)10232026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000010242026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (2.28ms)10252026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000010262026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)10272026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.16ms)10282026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.36ms)10292026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.48ms)10302026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)10312026/09/23 09:41:07 INFO Received uploads request method=POST path=/api/pending_closures10322026/09/23 09:41:07 INFO Received uploads request method=POST path=/api/pending_closures10332026/09/23 09:41:07 INFO Received uploads request method=POST path=/api/pending_closures10342026/09/23 09:41:07 OK 2_object_stats_trigger.sql (1.76ms)10352026/09/23 09:41:07 goose: up to current file version: 210362026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.1ms)10372026/09/23 09:41:07 goose: up to current file version: 210382026/09/23 09:41:07 OK 2_object_stats_trigger.sql (3.18ms)10392026/09/23 09:41:07 goose: up to current file version: 210402026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.94ms)10412026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.83ms)10422026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (1.61ms)10432026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000010442026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (1.7ms)10452026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000010462026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.65ms)10472026/09/23 09:41:07 OK 1_commit_pending_closure.sql (3.26ms)10482026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.33ms)10492026/09/23 09:41:07 goose: up to current file version: 210502026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.59ms)10512026/09/23 09:41:07 goose: up to current file version: 210522026/09/23 09:41:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45599/oidc10532026/09/23 09:41:07 INFO Received cleanup request method=DELETE path=/api/pending_closures10542026/09/23 09:41:07 INFO Aborted multipart uploads count=010552026/09/23 09:41:07 INFO Received uploads request method=POST path=/api/pending_closures10562026/09/23 09:41:07 INFO Received cleanup request method=DELETE path=/api/pending_closures10572026/09/23 09:41:07 INFO Aborted multipart uploads count=110582026/09/23 09:41:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10592026/09/23 09:41:07 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1060--- PASS: TestService_AuthMiddleware (0.50s)1061=== CONT TestService_AuthMiddleware_OIDC10622026-09-23 09:41:07.774 UTC [453] ERROR: Closure does not exist: id=110632026-09-23 09:41:07.774 UTC [453] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10642026-09-23 09:41:07.774 UTC [453] STATEMENT: -- name: CommitPendingClosure :exec1065 SELECT commit_pending_closure($1::bigint)1066 1067--- PASS: TestService_cleanupPendingClosuresHandler (0.50s)1068=== CONT TestReadRedirectNar10692026-09-23 09:41:07.785 UTC [477] ERROR: relation "goose_db_version" does not exist at character 3610702026-09-23 09:41:07.785 UTC [477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10712026/09/23 09:41:07 INFO Received uploads request method=POST path=/api/pending_closures10722026-09-23 09:41:07.809 UTC [479] ERROR: relation "goose_db_version" does not exist at character 3610732026-09-23 09:41:07.809 UTC [479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10742026/09/23 09:41:07 OK 20241026095416_initial_model.sql (17.96ms)10752026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)10762026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.02ms)1077--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.54s)1078=== CONT TestService_ReadAuthMiddleware10792026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)10802026/09/23 09:41:07 OK 20260905000000_add_claims.sql (3.53ms)10812026/09/23 09:41:07 OK 20241026095416_initial_model.sql (11.54ms)10822026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (4.15ms)10832026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000010842026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)10852026/09/23 09:41:07 INFO Received uploads request method=POST path=/api/pending_closures10862026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.7ms)10872026/09/23 09:41:07 OK 20251218171726_add_pins.sql (4.05ms)10882026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.63ms)10892026/09/23 09:41:07 goose: up to current file version: 210902026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (4.96ms)10912026/09/23 09:41:07 OK 20260905000000_add_claims.sql (3.58ms)10922026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (2.96ms)10932026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000010942026/09/23 09:41:07 OK 1_commit_pending_closure.sql (3.09ms)10952026/09/23 09:41:07 OK 2_object_stats_trigger.sql (1.65ms)10962026/09/23 09:41:07 goose: up to current file version: 210972026-09-23 09:41:07.855 UTC [482] ERROR: relation "goose_db_version" does not exist at character 3610982026-09-23 09:41:07.855 UTC [482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1099--- PASS: TestService_healthCheckHandler (0.58s)1100=== CONT TestReadProxyDisabled11012026/09/23 09:41:07 OK 20241026095416_initial_model.sql (11.75ms)11022026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)11032026/09/23 09:41:07 OK 20251218171726_add_pins.sql (3.61ms)11042026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)11052026/09/23 09:41:07 OK 20260905000000_add_claims.sql (3.96ms)11062026-09-23 09:41:07.890 UTC [485] ERROR: relation "goose_db_version" does not exist at character 3611072026-09-23 09:41:07.890 UTC [485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11082026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (3.3ms)11092026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000011102026/09/23 09:41:07 INFO Received uploads request method=POST path=/api/pending_closures11112026/09/23 09:41:07 OK 1_commit_pending_closure.sql (3.69ms)11122026/09/23 09:41:07 OK 2_object_stats_trigger.sql (2.13ms)11132026/09/23 09:41:07 goose: up to current file version: 211142026/09/23 09:41:07 OK 20241026095416_initial_model.sql (8.58ms)11152026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)11162026/09/23 09:41:07 OK 20251218171726_add_pins.sql (3.64ms)11172026/09/23 09:41:07 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11182026/09/23 09:41:07 INFO Received uploads request method=POST path=/api/pending_closures11192026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (5.23ms)1120--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.64s)1121=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11222026/09/23 09:41:07 OK 20260905000000_add_claims.sql (3.6ms)11232026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (2.04ms)11242026/09/23 09:41:07 goose: successfully migrated database to version: 202609200000001125--- PASS: TestService_Rustfstest (0.64s)1126=== CONT TestReadProxyRootRedirectsToIndexHTML11272026/09/23 09:41:07 OK 1_commit_pending_closure.sql (2.55ms)11282026/09/23 09:41:07 OK 2_object_stats_trigger.sql (958.17µs)11292026/09/23 09:41:07 goose: up to current file version: 211302026-09-23 09:41:07.931 UTC [489] ERROR: relation "goose_db_version" does not exist at character 3611312026-09-23 09:41:07.931 UTC [489] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11322026/09/23 09:41:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39625/oidc11332026/09/23 09:41:07 OK 20241026095416_initial_model.sql (11.69ms)11342026/09/23 09:41:07 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)11352026/09/23 09:41:07 OK 20251218171726_add_pins.sql (9.6ms)11362026/09/23 09:41:07 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)11372026/09/23 09:41:07 OK 20260905000000_add_claims.sql (4.39ms)11382026/09/23 09:41:07 OK 20260920000000_drop_claims.sql (3.86ms)11392026/09/23 09:41:07 goose: successfully migrated database to version: 2026092000000011402026/09/23 09:41:07 OK 1_commit_pending_closure.sql (3.06ms)11412026/09/23 09:41:07 OK 2_object_stats_trigger.sql (1.97ms)11422026/09/23 09:41:07 goose: up to current file version: 211432026-09-23 09:41:07.992 UTC [495] ERROR: relation "goose_db_version" does not exist at character 3611442026-09-23 09:41:07.992 UTC [495] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11452026-09-23 09:41:07.997 UTC [513] ERROR: relation "goose_db_version" does not exist at character 3611462026-09-23 09:41:07.997 UTC [513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11472026/09/23 09:41:08 OK 20241026095416_initial_model.sql (12.21ms)11482026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)11492026/09/23 09:41:08 OK 20241026095416_initial_model.sql (12.03ms)11502026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)11512026/09/23 09:41:08 INFO Aborted multipart uploads count=011522026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.11ms)11532026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.42ms)11542026/09/23 09:41:08 WARN Force mode enabled - objects will be deleted immediately without grace period11552026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)1156=== NAME TestNARDeduplicationMetadataUploadBug1157 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3344175753/001/store/40gswrdvqdpn03wkr1g9zqf11dy0wavy-file1.txt11582026/09/23 09:41:08 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=011592026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)11602026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.91ms)11612026/09/23 09:41:08 INFO Vacuumed table table=pending_closures11622026/09/23 09:41:08 INFO Vacuumed table table=pending_objects11632026/09/23 09:41:08 INFO Vacuumed table table=multipart_uploads11642026/09/23 09:41:08 INFO Vacuumed table table=closures11652026-09-23 09:41:08.027 UTC [532] ERROR: relation "goose_db_version" does not exist at character 3611662026-09-23 09:41:08.027 UTC [532] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11672026/09/23 09:41:08 INFO Vacuumed table table=objects11682026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.27ms)11692026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000011702026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.14ms)11712026/09/23 09:41:08 OK 1_commit_pending_closure.sql (1.9ms)11722026/09/23 09:41:08 OK 2_object_stats_trigger.sql (876.81µs)11732026/09/23 09:41:08 goose: up to current file version: 211742026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.27ms)11752026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000011762026/09/23 09:41:08 OK 1_commit_pending_closure.sql (1.81ms)11772026/09/23 09:41:08 OK 2_object_stats_trigger.sql (836.59µs)11782026/09/23 09:41:08 goose: up to current file version: 21179--- PASS: TestGCMetrics (0.75s)1180=== CONT TestService_AuthMiddleware_MTLSProxyHeader11812026/09/23 09:41:08 OK 20241026095416_initial_model.sql (9.57ms)11822026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (1.27ms)11832026/09/23 09:41:08 OK 20251218171726_add_pins.sql (2.83ms)1184--- PASS: TestMetricsInventory (0.77s)1185=== CONT TestReadProxyConditionalGet1186=== NAME TestClientCADerivations1187 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1543874601/001/store/y5wg5cfb1blr5bpwwfrndgkxv4bsiqrq-ca-test11882026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)11892026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.94ms)11902026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.03ms)11912026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000011922026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.28ms)11932026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2.2ms)11942026/09/23 09:41:08 goose: up to current file version: 211952026/09/23 09:41:08 WARN readiness check failed error="closed pool"1196--- PASS: TestService_readinessHandler (0.79s)1197=== CONT TestReadProxyHead1198=== NAME TestClientCADerivations1199 client_ca_test.go:139: Found 1 dependencies (including self)12002026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures12012026/09/23 09:41:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12022026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures12032026/09/23 09:41:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12042026/09/23 09:41:08 INFO Uploading 40gswrdvqdpn03wkr1g9zqf11dy0wavy-file1.txt (160B)12052026-09-23 09:41:08.115 UTC [610] ERROR: relation "goose_db_version" does not exist at character 3612062026-09-23 09:41:08.115 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12072026/09/23 09:41:08 WARN Failed to register uploaded object key=40gswrdvqdpn03wkr1g9zqf11dy0wavy.ls error="server returned 404: 404 page not found\n"12082026/09/23 09:41:08 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12092026/09/23 09:41:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12102026/09/23 09:41:08 INFO Signed narinfos id=1 count=112112026/09/23 09:41:08 INFO Uploading 1 narinfos12122026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures12132026/09/23 09:41:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12142026/09/23 09:41:08 WARN Failed to register uploaded object key=40gswrdvqdpn03wkr1g9zqf11dy0wavy.narinfo error="server returned 404: 404 page not found\n"12152026/09/23 09:41:08 OK 20241026095416_initial_model.sql (12.83ms)12162026/09/23 09:41:08 INFO Completed upload id=112172026/09/23 09:41:08 INFO Upload complete. (75ms)12182026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)1219=== NAME TestNARDeduplicationMetadataUploadBug1220 metadata_upload_test.go:54: Retrieved narinfo from S3:1221 StorePath: /build/TestNARDeduplicationMetadataUploadBug3344175753/001/store/40gswrdvqdpn03wkr1g9zqf11dy0wavy-file1.txt1222 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1223 Compression: zstd1224 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1225 NarSize: 1601226 References: 1227 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12282026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.62ms)1229 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1230 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1231 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12322026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (5.43ms)12332026/09/23 09:41:08 OK 20260905000000_add_claims.sql (2.68ms)12342026-09-23 09:41:08.151 UTC [632] ERROR: relation "goose_db_version" does not exist at character 3612352026-09-23 09:41:08.151 UTC [632] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12362026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.2ms)12372026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000012382026-09-23 09:41:08.152 UTC [634] ERROR: relation "goose_db_version" does not exist at character 3612392026-09-23 09:41:08.152 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12402026/09/23 09:41:08 OK 1_commit_pending_closure.sql (1.84ms)12412026/09/23 09:41:08 OK 2_object_stats_trigger.sql (1.01ms)12422026/09/23 09:41:08 goose: up to current file version: 212432026/09/23 09:41:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12442026/09/23 09:41:08 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12452026/09/23 09:41:08 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1246--- PASS: TestService_NativeMTLS (0.88s)1247=== CONT TestClientErrorHandling1248=== RUN TestClientErrorHandling/InvalidStorePath1249=== PAUSE TestClientErrorHandling/InvalidStorePath1250=== RUN TestClientErrorHandling/InvalidAuthToken1251=== PAUSE TestClientErrorHandling/InvalidAuthToken1252=== RUN TestClientErrorHandling/ServerNotAvailable1253=== PAUSE TestClientErrorHandling/ServerNotAvailable1254=== CONT TestReadProxyInvalidPath12552026/09/23 09:41:08 OK 20241026095416_initial_model.sql (9.31ms)12562026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)12572026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.62ms)12582026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)12592026/09/23 09:41:08 OK 20241026095416_initial_model.sql (16.37ms)1260=== NAME TestNARDeduplicationMetadataUploadBug1261 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3344175753/001/store/bzdc2fmj7313d1crppp51k5yibhj7x4j-file2.txt12622026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)12632026/09/23 09:41:08 OK 20260905000000_add_claims.sql (4.33ms)12642026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (3.28ms)12652026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000012662026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.66ms)12672026/09/23 09:41:08 OK 1_commit_pending_closure.sql (2.88ms)12682026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures12692026/09/23 09:41:08 OK 2_object_stats_trigger.sql (1.99ms)12702026/09/23 09:41:08 goose: up to current file version: 212712026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (5.77ms)12722026/09/23 09:41:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12732026/09/23 09:41:08 INFO Uploading y5wg5cfb1blr5bpwwfrndgkxv4bsiqrq-ca-test (144B)12742026/09/23 09:41:08 OK 20260905000000_add_claims.sql (6.39ms)12752026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (4.45ms)12762026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000012772026/09/23 09:41:08 WARN Failed to register uploaded object key=y5wg5cfb1blr5bpwwfrndgkxv4bsiqrq.ls error="server returned 404: 404 page not found\n"12782026/09/23 09:41:08 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"12792026/09/23 09:41:08 WARN Failed to register uploaded object key=log/1nb2cbmrc9sds67a6fzd2i45zj66fwg6-ca-test.drv error="server returned 404: 404 page not found\n"12802026/09/23 09:41:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1281--- PASS: TestCacheStatsHandler (0.84s)1282=== CONT TestPinProtectsFromGC12832026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.43ms)12842026/09/23 09:41:08 INFO Signed narinfos id=1 count=112852026/09/23 09:41:08 INFO Uploading 1 narinfos12862026/09/23 09:41:08 OK 2_object_stats_trigger.sql (3.27ms)12872026/09/23 09:41:08 goose: up to current file version: 212882026/09/23 09:41:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12892026/09/23 09:41:08 WARN Failed to register uploaded object key=y5wg5cfb1blr5bpwwfrndgkxv4bsiqrq.narinfo error="server returned 404: 404 page not found\n"12902026/09/23 09:41:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12912026/09/23 09:41:08 INFO Completed upload id=112922026/09/23 09:41:08 INFO Upload complete. (102ms)12932026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures1294=== NAME TestClientCADerivations1295 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1543874601/001/store/y5wg5cfb1blr5bpwwfrndgkxv4bsiqrq-ca-test1296 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1297 Compression: zstd1298 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1299 NarSize: 1441300 References: 1301 Deriver: /build/TestClientCADerivations1543874601/001/store/1nb2cbmrc9sds67a6fzd2i45zj66fwg6-ca-test.drv1302 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1303 client_ca_test.go:185: Checking for realisation files in S3...1304 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1305 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13062026-09-23 09:41:08.230 UTC [709] ERROR: relation "goose_db_version" does not exist at character 3613072026-09-23 09:41:08.230 UTC [709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13082026/09/23 09:41:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13092026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures13102026/09/23 09:41:08 OK 20241026095416_initial_model.sql (11.47ms)13112026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)13122026/09/23 09:41:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13132026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures13142026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.4ms)13152026/09/23 09:41:08 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13162026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (3.39ms)13172026/09/23 09:41:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13182026/09/23 09:41:08 INFO Signed narinfos id=2 count=113192026/09/23 09:41:08 INFO Uploading 1 narinfos13202026/09/23 09:41:08 WARN Failed to register uploaded object key=bzdc2fmj7313d1crppp51k5yibhj7x4j.ls error="server returned 404: 404 page not found\n"13212026/09/23 09:41:08 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13222026/09/23 09:41:08 WARN Failed to register uploaded object key=bzdc2fmj7313d1crppp51k5yibhj7x4j.narinfo error="server returned 404: 404 page not found\n"13232026/09/23 09:41:08 OK 20260905000000_add_claims.sql (10ms)13242026/09/23 09:41:08 INFO Completed upload id=213252026/09/23 09:41:08 INFO Upload complete. (56ms)13262026/09/23 09:41:08 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MmNiNDA1ZGMtM2Y0ZC00ZjY3LTkzM2MtZjhiMGVkMTZkNWQzLjM4NTlmYzcyLTE5NTktNDdkOS1hNjQ5LTE0OGRjZWFlMjA0ZngxNzkwMTU2NDY3NzM1NjM4NzY3 parts=1013272026/09/23 09:41:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1328=== NAME TestNARDeduplicationMetadataUploadBug1329 metadata_upload_test.go:76: Retrieved narinfo from S3:1330 StorePath: /build/TestNARDeduplicationMetadataUploadBug3344175753/001/store/bzdc2fmj7313d1crppp51k5yibhj7x4j-file2.txt1331 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1332 Compression: zstd1333 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1334 NarSize: 1601335 References: 1336 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13372026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.41ms)13382026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000013392026/09/23 09:41:08 OK 1_commit_pending_closure.sql (2.25ms)13402026/09/23 09:41:08 INFO Completed upload id=11341 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1342 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1343 {"version":1,"root":{"type":"regular","size":44}}13442026/09/23 09:41:08 OK 2_object_stats_trigger.sql (995.07µs)13452026/09/23 09:41:08 goose: up to current file version: 213462026/09/23 09:41:08 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013472026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures13482026-09-23 09:41:08.279 UTC [763] ERROR: relation "goose_db_version" does not exist at character 3613492026-09-23 09:41:08.279 UTC [763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1350--- PASS: TestNARDeduplicationMetadataUploadBug (1.00s)1351=== CONT TestReadProxy40413522026/09/23 09:41:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures1353--- PASS: TestReadRedirectUsesPublicS3URL (0.91s)1354=== CONT TestGCBugBareHashReferences13552026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures13562026/09/23 09:41:08 INFO Aborted multipart uploads count=013572026/09/23 09:41:08 OK 20241026095416_initial_model.sql (11.95ms)13582026/09/23 09:41:08 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=013592026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)13602026/09/23 09:41:08 INFO Vacuumed table table=pending_closures13612026/09/23 09:41:08 INFO Vacuumed table table=pending_objects13622026/09/23 09:41:08 OK 20251218171726_add_pins.sql (6.47ms)13632026/09/23 09:41:08 INFO Vacuumed table table=multipart_uploads13642026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.87ms)13652026/09/23 09:41:08 INFO Vacuumed table table=closures13662026/09/23 09:41:08 INFO Vacuumed table table=objects13672026/09/23 09:41:08 OK 20260905000000_add_claims.sql (4.49ms)13682026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (3.28ms)13692026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000013702026/09/23 09:41:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13712026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.43ms)13722026/09/23 09:41:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13732026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2.37ms)13742026/09/23 09:41:08 goose: up to current file version: 213752026/09/23 09:41:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmNiNDA1ZGMtM2Y0ZC00ZjY3LTkzM2MtZjhiMGVkMTZkNWQzLmFhN2EyNDVjLTIxZmItNGMyZi1hN2VjLTk1NTc4MDY5ZjlmZXgxNzkwMTU2NDY4MjkyMDM0NTQx13762026/09/23 09:41:08 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001377--- PASS: TestReadProxyRangeRequest (0.96s)1378=== CONT TestReadProxyNarStreaming1379--- PASS: TestService_createPendingClosureHandler (1.05s)1380=== CONT TestReadProxyNarinfoAlreadyDecompressed13812026/09/23 09:41:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmNiNDA1ZGMtM2Y0ZC00ZjY3LTkzM2MtZjhiMGVkMTZkNWQzLmFhN2EyNDVjLTIxZmItNGMyZi1hN2VjLTk1NTc4MDY5ZjlmZXgxNzkwMTU2NDY4MjkyMDM0NTQx parts=11382--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.97s)1383=== CONT TestClientSharedPathCommittedMidPush1384--- PASS: TestService_ReadScope_PublicByDefault (0.97s)1385=== CONT TestReadProxyNarinfo13862026/09/23 09:41:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MmNiNDA1ZGMtM2Y0ZC00ZjY3LTkzM2MtZjhiMGVkMTZkNWQzLjM5MjI5Yjk1LTg0OGMtNDY3Yi1iYzliLTI2NmUzM2UyYzlkMXgxNzkwMTU2NDY3ODQxOTY5MjAy parts=1013872026/09/23 09:41:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13882026/09/23 09:41:08 INFO Completed upload id=113892026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures13902026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures13912026-09-23 09:41:08.353 UTC [836] ERROR: relation "goose_db_version" does not exist at character 3613922026-09-23 09:41:08.353 UTC [836] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13932026-09-23 09:41:08.354 UTC [837] ERROR: relation "goose_db_version" does not exist at character 3613942026-09-23 09:41:08.354 UTC [837] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13952026/09/23 09:41:08 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13962026/09/23 09:41:08 WARN Found objects in DB but missing from S3, will re-upload count=11397--- PASS: TestService_verifyS3Integrity (1.08s)1398=== CONT TestLeadEndsOnShutdown1399--- PASS: TestReadRedirectKeepsNarinfoProxied (0.68s)1400=== NAME TestClientCADerivations1401 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1402 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1403=== CONT TestClientWithDependencies1404=== NAME TestClientCADerivations1405 error: binary cache 's3://bucket12?endpoint=http://localhost:41645®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1543874601/001/store'1406 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 114072026/09/23 09:41:08 OK 20241026095416_initial_model.sql (21.26ms)14082026/09/23 09:41:08 OK 20241026095416_initial_model.sql (24.96ms)14092026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)1410--- PASS: TestClientCADerivations (1.11s)1411=== CONT TestIsValidCachePath1412=== RUN TestIsValidCachePath/narinfo1413=== PAUSE TestIsValidCachePath/narinfo1414=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1415=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1416=== RUN TestIsValidCachePath/nar_zst1417=== PAUSE TestIsValidCachePath/nar_zst1418=== RUN TestIsValidCachePath/nar_xz1419=== PAUSE TestIsValidCachePath/nar_xz1420=== RUN TestIsValidCachePath/nar_bz21421=== PAUSE TestIsValidCachePath/nar_bz21422=== RUN TestIsValidCachePath/nar_uncompressed1423=== PAUSE TestIsValidCachePath/nar_uncompressed1424=== RUN TestIsValidCachePath/ls1425=== PAUSE TestIsValidCachePath/ls1426=== RUN TestIsValidCachePath/log1427=== PAUSE TestIsValidCachePath/log1428=== RUN TestIsValidCachePath/realisation1429=== PAUSE TestIsValidCachePath/realisation1430=== RUN TestIsValidCachePath/nix-cache-info1431=== PAUSE TestIsValidCachePath/nix-cache-info1432=== RUN TestIsValidCachePath/index.html1433=== PAUSE TestIsValidCachePath/index.html1434=== RUN TestIsValidCachePath/traversal_parent1435=== PAUSE TestIsValidCachePath/traversal_parent14362026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.88ms)1437=== RUN TestIsValidCachePath/traversal_in_middle1438=== PAUSE TestIsValidCachePath/traversal_in_middle1439=== RUN TestIsValidCachePath/invalid_char_e1440=== PAUSE TestIsValidCachePath/invalid_char_e1441=== RUN TestIsValidCachePath/invalid_char_u1442=== PAUSE TestIsValidCachePath/invalid_char_u1443=== RUN TestIsValidCachePath/random_path1444=== PAUSE TestIsValidCachePath/random_path1445=== RUN TestIsValidCachePath/empty1446=== PAUSE TestIsValidCachePath/empty1447=== RUN TestIsValidCachePath/leading_slash1448=== PAUSE TestIsValidCachePath/leading_slash1449=== RUN TestIsValidCachePath/wrong_extension1450=== PAUSE TestIsValidCachePath/wrong_extension1451=== RUN TestIsValidCachePath/short_hash1452=== PAUSE TestIsValidCachePath/short_hash1453=== CONT TestLeadElectsOneAndHandsOver14542026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.95ms)14552026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.93ms)14562026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)14572026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)14582026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.73ms)14592026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (3.67ms)14602026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000014612026/09/23 09:41:08 OK 20260905000000_add_claims.sql (5.03ms)14622026-09-23 09:41:08.404 UTC [882] ERROR: relation "goose_db_version" does not exist at character 3614632026-09-23 09:41:08.404 UTC [882] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14642026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.72ms)14652026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (6.09ms)14662026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000014672026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2.67ms)14682026/09/23 09:41:08 goose: up to current file version: 21469=== RUN TestService_RequireScope_OIDC/builder_may_write1470=== PAUSE TestService_RequireScope_OIDC/builder_may_write1471=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1472=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1473=== RUN TestService_RequireScope_OIDC/ops_may_admin1474=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1475=== RUN TestService_RequireScope_OIDC/ops_may_not_write1476=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1477=== RUN TestService_RequireScope_OIDC/reader_may_not_write1478=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1479=== RUN TestService_RequireScope_OIDC/static_token_may_admin14802026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.92ms)1481=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1482=== RUN TestService_RequireScope_OIDC/static_token_may_write1483=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1484=== RUN TestService_RequireScope_OIDC/reader_may_read1485=== PAUSE TestService_RequireScope_OIDC/reader_may_read1486=== RUN TestService_RequireScope_OIDC/writer_implies_read1487=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1488=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1489=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1490=== CONT TestClientMultipleUploads14912026/09/23 09:41:08 OK 2_object_stats_trigger.sql (3.72ms)14922026/09/23 09:41:08 goose: up to current file version: 214932026-09-23 09:41:08.428 UTC [885] ERROR: relation "goose_db_version" does not exist at character 3614942026-09-23 09:41:08.428 UTC [885] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14952026/09/23 09:41:08 OK 20241026095416_initial_model.sql (18.04ms)14962026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)14972026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.96ms)14982026-09-23 09:41:08.439 UTC [886] ERROR: relation "goose_db_version" does not exist at character 3614992026-09-23 09:41:08.439 UTC [886] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15002026-09-23 09:41:08.441 UTC [887] ERROR: relation "goose_db_version" does not exist at character 3615012026-09-23 09:41:08.441 UTC [887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15022026-09-23 09:41:08.442 UTC [888] ERROR: relation "goose_db_version" does not exist at character 3615032026-09-23 09:41:08.442 UTC [888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15042026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (6.24ms)1505--- PASS: TestReadRedirectNar (0.67s)1506=== CONT TestProxyHeadersOnlyTrustedOnSocket15072026/09/23 09:41:08 OK 20260905000000_add_claims.sql (5.36ms)15082026/09/23 09:41:08 OK 20241026095416_initial_model.sql (14.47ms)15092026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (4.09ms)15102026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000015112026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)15122026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.7ms)15132026/09/23 09:41:08 OK 20251218171726_add_pins.sql (5.02ms)15142026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2.71ms)15152026/09/23 09:41:08 OK 20241026095416_initial_model.sql (13.17ms)15162026/09/23 09:41:08 goose: up to current file version: 215172026/09/23 09:41:08 OK 20241026095416_initial_model.sql (13.39ms)15182026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)15192026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (5.48ms)15202026/09/23 09:41:08 OK 20241026095416_initial_model.sql (14.38ms)15212026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (4.02ms)15222026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)15232026/09/23 09:41:08 OK 20251218171726_add_pins.sql (5.2ms)15242026/09/23 09:41:08 OK 20260905000000_add_claims.sql (5.51ms)15252026/09/23 09:41:08 OK 20251218171726_add_pins.sql (5.09ms)15262026/09/23 09:41:08 OK 20251218171726_add_pins.sql (5.34ms)15272026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (5.57ms)15282026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (5.4ms)15292026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000015302026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)1531--- PASS: TestService_ReadAuthMiddleware (0.66s)1532=== CONT TestResolveDBConnectionString15332026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.95ms)15342026-09-23 09:41:08.478 UTC [891] ERROR: relation "goose_db_version" does not exist at character 3615352026-09-23 09:41:08.478 UTC [891] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1536=== RUN TestResolveDBConnectionString/flag_wins1537=== PAUSE TestResolveDBConnectionString/flag_wins1538=== RUN TestResolveDBConnectionString/file_when_flag_empty1539=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1540=== RUN TestResolveDBConnectionString/missing_file_is_an_error1541=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1542=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1543=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1544=== RUN TestResolveDBConnectionString/nothing_configured1545=== PAUSE TestResolveDBConnectionString/nothing_configured1546=== CONT TestClientIntegration15472026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.73ms)15482026/09/23 09:41:08 OK 20260905000000_add_claims.sql (6.39ms)15492026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2.85ms)15502026/09/23 09:41:08 goose: up to current file version: 215512026/09/23 09:41:08 OK 20260905000000_add_claims.sql (6.53ms)15522026/09/23 09:41:08 OK 20260905000000_add_claims.sql (5.63ms)15532026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (3.66ms)15542026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000015552026-09-23 09:41:08.487 UTC [893] ERROR: relation "goose_db_version" does not exist at character 3615562026-09-23 09:41:08.487 UTC [893] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15572026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (12.97ms)15582026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000015592026/09/23 09:41:08 OK 1_commit_pending_closure.sql (11.92ms)15602026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (13.77ms)15612026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000015622026/09/23 09:41:08 OK 20241026095416_initial_model.sql (12.32ms)15632026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.34ms)15642026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2.31ms)15652026/09/23 09:41:08 goose: up to current file version: 215662026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)15672026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.13ms)15682026/09/23 09:41:08 OK 2_object_stats_trigger.sql (3.05ms)15692026/09/23 09:41:08 goose: up to current file version: 215702026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2.26ms)15712026/09/23 09:41:08 goose: up to current file version: 215722026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.35ms)15732026/09/23 09:41:08 OK 20241026095416_initial_model.sql (12.03ms)15742026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (13.4ms)15752026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (10.98ms)15762026/09/23 09:41:08 OK 20260905000000_add_claims.sql (4.71ms)1577--- PASS: TestReadProxyDisabled (0.66s)1578=== CONT TestParseSingleRange1579=== RUN TestParseSingleRange/none1580=== PAUSE TestParseSingleRange/none1581=== RUN TestParseSingleRange/unknown_unit15822026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.19ms)1583=== PAUSE TestParseSingleRange/unknown_unit1584=== RUN TestParseSingleRange/multi-range_ignored1585=== PAUSE TestParseSingleRange/multi-range_ignored1586=== RUN TestParseSingleRange/malformed_no_dash1587=== PAUSE TestParseSingleRange/malformed_no_dash1588=== RUN TestParseSingleRange/malformed_both_empty1589=== PAUSE TestParseSingleRange/malformed_both_empty1590=== RUN TestParseSingleRange/malformed_end_before_start1591=== PAUSE TestParseSingleRange/malformed_end_before_start1592=== RUN TestParseSingleRange/closed1593=== PAUSE TestParseSingleRange/closed1594=== RUN TestParseSingleRange/open-ended1595=== PAUSE TestParseSingleRange/open-ended1596=== RUN TestParseSingleRange/end_clamped_to_size1597=== PAUSE TestParseSingleRange/end_clamped_to_size1598=== RUN TestParseSingleRange/suffix1599=== PAUSE TestParseSingleRange/suffix1600=== RUN TestParseSingleRange/suffix_exceeds_size1601=== PAUSE TestParseSingleRange/suffix_exceeds_size1602=== RUN TestParseSingleRange/single_byte1603=== PAUSE TestParseSingleRange/single_byte1604=== RUN TestParseSingleRange/start_past_EOF1605=== PAUSE TestParseSingleRange/start_past_EOF1606=== RUN TestParseSingleRange/start_far_past_EOF1607=== PAUSE TestParseSingleRange/start_far_past_EOF1608=== CONT TestCreatePin_ReservedPins16092026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (3.66ms)16102026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000016112026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)16122026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.7ms)16132026-09-23 09:41:08.533 UTC [895] ERROR: relation "goose_db_version" does not exist at character 3616142026-09-23 09:41:08.533 UTC [895] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16152026/09/23 09:41:08 OK 2_object_stats_trigger.sql (1.91ms)16162026/09/23 09:41:08 goose: up to current file version: 216172026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.85ms)16182026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (3.18ms)16192026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000016202026-09-23 09:41:08.539 UTC [896] ERROR: relation "goose_db_version" does not exist at character 3616212026-09-23 09:41:08.539 UTC [896] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16222026/09/23 09:41:08 OK 1_commit_pending_closure.sql (2.92ms)16232026/09/23 09:41:08 OK 2_object_stats_trigger.sql (1.8ms)16242026/09/23 09:41:08 goose: up to current file version: 216252026/09/23 09:41:08 OK 20241026095416_initial_model.sql (11.42ms)16262026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.62ms)16272026/09/23 09:41:08 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16282026/09/23 09:41:08 WARN mTLS auth: bound subjects configured but subject DN unavailable16292026/09/23 09:41:08 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1630--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.64s)1631=== CONT TestOrphanedObjectsGC16322026/09/23 09:41:08 OK 20241026095416_initial_model.sql (10.37ms)16332026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.03ms)16342026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)16352026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (3.29ms)16362026/09/23 09:41:08 OK 20251218171726_add_pins.sql (2.56ms)16372026-09-23 09:41:08.563 UTC [898] ERROR: relation "goose_db_version" does not exist at character 3616382026-09-23 09:41:08.563 UTC [898] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16392026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.73ms)16402026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)16412026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.26ms)16422026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000016432026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.32ms)16442026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.49ms)16452026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (3.01ms)16462026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000016472026/09/23 09:41:08 OK 2_object_stats_trigger.sql (1.56ms)16482026/09/23 09:41:08 goose: up to current file version: 216492026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.19ms)16502026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2ms)16512026/09/23 09:41:08 goose: up to current file version: 216522026/09/23 09:41:08 OK 20241026095416_initial_model.sql (10.85ms)16532026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)16542026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.7ms)16552026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)1656--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.67s)1657=== CONT TestServerTLSConfig1658=== RUN TestServerTLSConfig/no_client_CA1659=== PAUSE TestServerTLSConfig/no_client_CA1660=== RUN TestServerTLSConfig/missing_CA_file1661=== PAUSE TestServerTLSConfig/missing_CA_file1662=== RUN TestServerTLSConfig/not_a_PEM_file1663=== PAUSE TestServerTLSConfig/not_a_PEM_file1664=== CONT TestResurrectedObjectNotDeleted16652026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.79ms)16662026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.91ms)16672026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000016682026/09/23 09:41:08 OK 1_commit_pending_closure.sql (2.8ms)16692026/09/23 09:41:08 OK 2_object_stats_trigger.sql (1.96ms)16702026/09/23 09:41:08 goose: up to current file version: 21671=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1672=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1673=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1674=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1675=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1676=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1677=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1678=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1679=== CONT TestMultipartCleanup16802026-09-23 09:41:08.622 UTC [902] ERROR: relation "goose_db_version" does not exist at character 3616812026-09-23 09:41:08.622 UTC [902] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16822026/09/23 09:41:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43819/oidc16832026/09/23 09:41:08 OK 20241026095416_initial_model.sql (14.09ms)16842026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)1685--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.61s)1686=== CONT TestObjectStatsTrigger16872026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.14ms)16882026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (11.84ms)16892026/09/23 09:41:08 OK 20260905000000_add_claims.sql (4.19ms)16902026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (3.41ms)16912026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000016922026/09/23 09:41:08 OK 1_commit_pending_closure.sql (3.46ms)16932026-09-23 09:41:08.674 UTC [909] ERROR: relation "goose_db_version" does not exist at character 3616942026-09-23 09:41:08.674 UTC [909] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16952026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2.31ms)16962026/09/23 09:41:08 goose: up to current file version: 21697--- PASS: TestReadProxyHead (0.62s)1698=== CONT TestOrphanedObjectsGCStressTest16992026/09/23 09:41:08 OK 20241026095416_initial_model.sql (11.9ms)17002026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)17012026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.71ms)17022026-09-23 09:41:08.701 UTC [911] ERROR: relation "goose_db_version" does not exist at character 3617032026-09-23 09:41:08.701 UTC [911] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17042026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)17052026/09/23 09:41:08 OK 20260905000000_add_claims.sql (4.4ms)17062026-09-23 09:41:08.710 UTC [913] ERROR: relation "goose_db_version" does not exist at character 3617072026-09-23 09:41:08.710 UTC [913] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17082026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (4.18ms)17092026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000017102026/09/23 09:41:08 OK 1_commit_pending_closure.sql (4.4ms)17112026/09/23 09:41:08 OK 20241026095416_initial_model.sql (11.7ms)17122026/09/23 09:41:08 OK 2_object_stats_trigger.sql (2ms)17132026/09/23 09:41:08 goose: up to current file version: 217142026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)1715--- PASS: TestReadProxyConditionalGet (0.67s)1716=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17172026/09/23 09:41:08 INFO Received uploads request method=POST path=/1718=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17192026/09/23 09:41:08 INFO Received complete multipart upload request method=POST path=/1720=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17212026/09/23 09:41:08 INFO Received uploads request method=POST path=/1722=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17232026/09/23 09:41:08 INFO Received request for more parts method=POST path=/1724=== CONT TestProxyWriteTimeout/narinfo1725=== CONT TestProxyWriteTimeout/10_GiB_nar1726=== CONT TestProxyWriteTimeout/unknown_size1727=== CONT TestProxyWriteTimeout/1_GiB_nar1728=== CONT TestCacheConfigHandler/full_config,_no_issuer1729=== CONT TestCacheConfigHandler/no_signing_keys1730=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1731--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1732 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1733 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1734 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1735 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1736=== CONT TestCacheConfigHandler/no_cache_url_configured1737--- PASS: TestProxyWriteTimeout (0.08s)1738 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1739 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1740 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1741 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1742=== CONT TestIsValidUploadKey/narinfo1743=== CONT TestIsValidUploadKey/unknown_type1744=== CONT TestIsValidUploadKey/empty_key1745--- PASS: TestCacheConfigHandler (0.00s)1746 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1747 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1748 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1749 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1750=== CONT TestIsValidUploadKey/absolute1751=== CONT TestIsValidUploadKey/traversal_nar1752=== CONT TestIsValidUploadKey/traversal1753=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1754=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1755=== CONT TestIsValidUploadKey/narinfo_key,_nar_type17562026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.21ms)1757=== CONT TestIsValidUploadKey/index.html1758=== CONT TestIsValidUploadKey/nix-cache-info1759=== CONT TestIsValidUploadKey/realisation_plus_in_output1760=== CONT TestIsValidUploadKey/realisation1761=== CONT TestIsValidUploadKey/build_log_equals1762=== CONT TestIsValidUploadKey/build_log_question_mark1763=== CONT TestIsValidUploadKey/build_log_plus_in_name1764=== CONT TestIsValidUploadKey/build_log_home-manager_file1765=== CONT TestIsValidUploadKey/build_log1766=== CONT TestIsValidUploadKey/listing1767=== CONT TestIsValidUploadKey/nar_plain1768=== CONT TestIsValidUploadKey/nar_xz1769=== CONT TestIsValidUploadKey/nar_zst1770=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1771--- PASS: TestIsValidUploadKey (0.09s)1772 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1773 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1774 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1775 --- PASS: TestIsValidUploadKey/absolute (0.00s)1776 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1777 --- PASS: TestIsValidUploadKey/traversal (0.00s)1778 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1779 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1780 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1781 --- PASS: TestIsValidUploadKey/index.html (0.00s)1782 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1783 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1784 --- PASS: TestIsValidUploadKey/realisation (0.00s)1785 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1786 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1787 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1788 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1789 --- PASS: TestIsValidUploadKey/build_log (0.00s)1790 --- PASS: TestIsValidUploadKey/listing (0.00s)1791 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1792 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1793 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)17942026/09/23 09:41:08 INFO Received uploads request method=POST path=/17952026/09/23 09:41:08 OK 20241026095416_initial_model.sql (11.55ms)17962026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)17972026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2ms)17982026-09-23 09:41:08.732 UTC [914] ERROR: relation "goose_db_version" does not exist at character 3617992026-09-23 09:41:08.732 UTC [914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18002026/09/23 09:41:08 OK 20260905000000_add_claims.sql (4.31ms)18012026/09/23 09:41:08 OK 20251218171726_add_pins.sql (4.53ms)18022026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.92ms)18032026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000018042026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)18052026/09/23 09:41:08 OK 1_commit_pending_closure.sql (2.74ms)18062026/09/23 09:41:08 OK 2_object_stats_trigger.sql (1.92ms)18072026/09/23 09:41:08 goose: up to current file version: 218082026/09/23 09:41:08 OK 20260905000000_add_claims.sql (4.27ms)18092026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (3.33ms)18102026/09/23 09:41:08 goose: successfully migrated database to version: 202609200000001811--- PASS: TestReadProxyInvalidPath (0.59s)1812=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18132026/09/23 09:41:08 INFO Received request for more parts method=POST path=/18142026/09/23 09:41:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18152026/09/23 09:41:08 OK 20241026095416_initial_model.sql (16.93ms)18162026/09/23 09:41:08 OK 1_commit_pending_closure.sql (8.81ms)18172026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)18182026/09/23 09:41:08 OK 2_object_stats_trigger.sql (1.16ms)18192026/09/23 09:41:08 goose: up to current file version: 218202026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.34ms)18212026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (2.86ms)18222026-09-23 09:41:08.767 UTC [915] ERROR: relation "goose_db_version" does not exist at character 3618232026-09-23 09:41:08.767 UTC [915] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18242026/09/23 09:41:08 OK 20260905000000_add_claims.sql (4.12ms)18252026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.22ms)18262026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000018272026/09/23 09:41:08 OK 1_commit_pending_closure.sql (1.83ms)18282026/09/23 09:41:08 OK 2_object_stats_trigger.sql (988.09µs)18292026/09/23 09:41:08 goose: up to current file version: 218302026/09/23 09:41:08 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MmNiNDA1ZGMtM2Y0ZC00ZjY3LTkzM2MtZjhiMGVkMTZkNWQzLjIxYWFiYmFiLTVkNTQtNDg3Ni1iNjQyLWU1ZjAwNzc1MmZhN3gxNzkwMTU2NDY4MTM4MDc4NzA3 parts=1218312026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures1832--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.50s)1833=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18342026/09/23 09:41:08 INFO Received complete multipart upload request method=POST path=/18352026/09/23 09:41:08 OK 20241026095416_initial_model.sql (9.83ms)18362026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)18372026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.46ms)18382026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)18392026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.09ms)18402026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (1.91ms)18412026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000018422026/09/23 09:41:08 OK 1_commit_pending_closure.sql (1.93ms)18432026/09/23 09:41:08 OK 2_object_stats_trigger.sql (999.15µs)18442026/09/23 09:41:08 goose: up to current file version: 21845--- PASS: TestReadProxy404 (0.55s)1846=== CONT TestClientErrorHandling/InvalidStorePath18472026/09/23 09:41:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1848=== NAME TestPinProtectsFromGC1849 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3109650831/001/store/kpw49q3mi9i0fmn95q1qcsgg2gi9a6cj-pinned-file.txt1850 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3109650831/001/store/i5ln99w35lwqfkyn8brzb3dy1pws9l9q-unpinned-file.txt1851=== CONT TestClientErrorHandling/InvalidAuthToken1852--- PASS: TestReadProxyNarStreaming (0.54s)1853=== CONT TestClientErrorHandling/ServerNotAvailable1854=== CONT TestIsValidCachePath/narinfo1855=== CONT TestIsValidCachePath/invalid_char_e1856=== CONT TestIsValidCachePath/traversal_in_middle1857=== CONT TestIsValidCachePath/traversal_parent1858=== CONT TestIsValidCachePath/index.html1859=== CONT TestIsValidCachePath/nix-cache-info18602026/09/23 09:41:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MmNiNDA1ZGMtM2Y0ZC00ZjY3LTkzM2MtZjhiMGVkMTZkNWQzLjZlZmI3YmY0LTJiYjYtNGU3Yi1hZWE1LTA1MjQyZjkwNjA5YngxNzkwMTU2NDY4MjM0MDk2OTky parts=121861=== CONT TestIsValidCachePath/realisation1862=== CONT TestIsValidCachePath/log1863=== CONT TestIsValidCachePath/ls1864=== CONT TestIsValidCachePath/invalid_char_u1865=== CONT TestIsValidCachePath/nar_uncompressed1866=== CONT TestIsValidCachePath/nar_bz21867=== CONT TestIsValidCachePath/nar_xz1868=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1869=== CONT TestIsValidCachePath/leading_slash1870=== CONT TestIsValidCachePath/short_hash1871=== CONT TestIsValidCachePath/wrong_extension1872=== CONT TestIsValidCachePath/empty1873=== CONT TestIsValidCachePath/random_path1874=== CONT TestIsValidCachePath/nar_zst1875=== CONT TestService_RequireScope_OIDC/builder_may_write1876--- PASS: TestIsValidCachePath (0.00s)1877 --- PASS: TestIsValidCachePath/narinfo (0.00s)1878 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1879 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1880 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1881 --- PASS: TestIsValidCachePath/index.html (0.00s)1882 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1883 --- PASS: TestIsValidCachePath/realisation (0.00s)1884 --- PASS: TestIsValidCachePath/log (0.00s)1885 --- PASS: TestIsValidCachePath/ls (0.00s)1886 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1887 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1888 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1889 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1890 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1891 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1892 --- PASS: TestIsValidCachePath/short_hash (0.00s)1893 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1894 --- PASS: TestIsValidCachePath/empty (0.00s)1895 --- PASS: TestIsValidCachePath/random_path (0.00s)1896 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1897--- PASS: TestRedundantMultipartUpload (1.52s)1898=== CONT TestService_RequireScope_OIDC/static_token_may_admin1899=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1900=== CONT TestService_RequireScope_OIDC/writer_implies_read1901=== CONT TestService_RequireScope_OIDC/reader_may_read1902=== CONT TestService_RequireScope_OIDC/static_token_may_write1903=== CONT TestService_RequireScope_OIDC/ops_may_not_write1904=== CONT TestService_RequireScope_OIDC/reader_may_not_write1905=== CONT TestService_RequireScope_OIDC/ops_may_admin1906=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1907=== CONT TestResolveDBConnectionString/flag_wins1908=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1909=== CONT TestResolveDBConnectionString/nothing_configured1910=== CONT TestResolveDBConnectionString/file_when_flag_empty1911=== CONT TestParseSingleRange/none1912=== CONT TestResolveDBConnectionString/missing_file_is_an_error1913=== CONT TestParseSingleRange/start_far_past_EOF1914=== CONT TestParseSingleRange/single_byte1915=== CONT TestParseSingleRange/suffix_exceeds_size1916=== CONT TestParseSingleRange/suffix1917=== CONT TestParseSingleRange/start_past_EOF1918--- PASS: TestResolveDBConnectionString (0.00s)1919 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1920 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1921 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1922 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1923 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1924=== CONT TestParseSingleRange/open-ended1925=== CONT TestParseSingleRange/closed1926=== CONT TestParseSingleRange/end_clamped_to_size1927=== CONT TestParseSingleRange/malformed_both_empty1928=== CONT TestParseSingleRange/malformed_no_dash1929=== CONT TestParseSingleRange/multi-range_ignored1930=== CONT TestParseSingleRange/unknown_unit1931=== CONT TestParseSingleRange/malformed_end_before_start1932=== CONT TestServerTLSConfig/no_client_CA1933=== CONT TestServerTLSConfig/missing_CA_file1934=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1935--- PASS: TestParseSingleRange (0.00s)1936 --- PASS: TestParseSingleRange/none (0.00s)1937 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1938 --- PASS: TestParseSingleRange/single_byte (0.00s)1939 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1940 --- PASS: TestParseSingleRange/suffix (0.00s)1941 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1942 --- PASS: TestParseSingleRange/open-ended (0.00s)1943 --- PASS: TestParseSingleRange/closed (0.00s)1944 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1945 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1946 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1947 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1948 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1949 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1950=== CONT TestServerTLSConfig/not_a_PEM_file1951--- PASS: TestService_RequireScope_OIDC (0.97s)1952 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1960 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1961 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1962--- PASS: TestServerTLSConfig (0.00s)1963 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1964 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1965 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1966=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19672026/09/23 09:41:08 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]1968=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1969=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured19702026/09/23 09:41:08 WARN Authentication failed token_preview=eyJhbGciOi...9wsHvMtLPw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1971--- PASS: TestService_AuthMiddleware_OIDC (0.84s)1972 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1973 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1974 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1975 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)19762026-09-23 09:41:08.902 UTC [975] ERROR: relation "goose_db_version" does not exist at character 3619772026-09-23 09:41:08.902 UTC [975] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19782026/09/23 09:41:08 OK 20241026095416_initial_model.sql (12.38ms)1979--- PASS: TestReadProxyNarinfo (0.58s)19802026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)19812026/09/23 09:41:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19822026/09/23 09:41:08 INFO Received uploads request method=POST path=/api/pending_closures19832026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.52ms)19842026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)19852026/09/23 09:41:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19862026/09/23 09:41:08 INFO Uploading kpw49q3mi9i0fmn95q1qcsgg2gi9a6cj-pinned-file.txt (128B)19872026/09/23 09:41:08 OK 20260905000000_add_claims.sql (3.36ms)19882026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (2.05ms)19892026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000019902026-09-23 09:41:08.938 UTC [1026] ERROR: relation "goose_db_version" does not exist at character 3619912026-09-23 09:41:08.938 UTC [1026] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19922026/09/23 09:41:08 OK 1_commit_pending_closure.sql (2.01ms)19932026/09/23 09:41:08 OK 2_object_stats_trigger.sql (956.31µs)19942026/09/23 09:41:08 goose: up to current file version: 219952026/09/23 09:41:08 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"19962026/09/23 09:41:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19972026/09/23 09:41:08 WARN Failed to register uploaded object key=kpw49q3mi9i0fmn95q1qcsgg2gi9a6cj.ls error="server returned 404: 404 page not found\n"19982026/09/23 09:41:08 INFO Signed narinfos id=1 count=119992026/09/23 09:41:08 INFO Uploading 1 narinfos20002026/09/23 09:41:08 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/present20012026/09/23 09:41:08 INFO lead: acquired remote=192.0.2.1:123420022026/09/23 09:41:08 INFO lead: released remote=192.0.2.1:12342003--- PASS: TestLeadEndsOnShutdown (0.59s)20042026/09/23 09:41:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20052026/09/23 09:41:08 WARN Failed to register uploaded object key=kpw49q3mi9i0fmn95q1qcsgg2gi9a6cj.narinfo error="server returned 404: 404 page not found\n"20062026/09/23 09:41:08 OK 20241026095416_initial_model.sql (8.41ms)20072026/09/23 09:41:08 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)20082026/09/23 09:41:08 OK 20251218171726_add_pins.sql (3.36ms)20092026/09/23 09:41:08 INFO Completed upload id=120102026/09/23 09:41:08 INFO Upload complete. (68ms)20112026/09/23 09:41:08 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)20122026/09/23 09:41:08 OK 20260905000000_add_claims.sql (2.61ms)20132026/09/23 09:41:08 OK 20260920000000_drop_claims.sql (1.48ms)20142026/09/23 09:41:08 goose: successfully migrated database to version: 2026092000000020152026/09/23 09:41:08 OK 1_commit_pending_closure.sql (1.75ms)20162026/09/23 09:41:08 OK 2_object_stats_trigger.sql (793.13µs)20172026/09/23 09:41:08 goose: up to current file version: 22018--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.65s)20192026/09/23 09:41:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20202026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures20212026/09/23 09:41:09 INFO lead: acquired remote=192.0.2.1:123420222026/09/23 09:41:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20232026/09/23 09:41:09 INFO Uploading i5ln99w35lwqfkyn8brzb3dy1pws9l9q-unpinned-file.txt (128B)2024--- PASS: TestGCBugBareHashReferences (0.75s)20252026/09/23 09:41:09 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20262026/09/23 09:41:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20272026/09/23 09:41:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20282026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures20292026/09/23 09:41:09 WARN Failed to register uploaded object key=i5ln99w35lwqfkyn8brzb3dy1pws9l9q.ls error="server returned 404: 404 page not found\n"20302026/09/23 09:41:09 INFO Signed narinfos id=2 count=120312026/09/23 09:41:09 INFO Uploading 1 narinfos20322026/09/23 09:41:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20332026/09/23 09:41:09 WARN Failed to register uploaded object key=i5ln99w35lwqfkyn8brzb3dy1pws9l9q.narinfo error="server returned 404: 404 page not found\n"20342026/09/23 09:41:09 INFO Completed upload id=220352026/09/23 09:41:09 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.983101ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20362026/09/23 09:41:09 INFO Upload complete. (55ms)20372026/09/23 09:41:09 INFO Starting HTTP server address=127.0.0.1:3692520382026/09/23 09:41:09 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1846419445/001/proxy.sock20392026/09/23 09:41:09 WARN mTLS auth: subject not in bound subjects subject="CN=someone"20402026/09/23 09:41:09 INFO Shutdown signal received, draining in-flight requests timeout=10s2041--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.61s)20422026/09/23 09:41:09 INFO Received create pin request method=POST path=/api/pins/myapp2043=== NAME TestClientWithDependencies2044 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2849821803/001/store/mfapbsm5pzvw2zyivycj74di0mpabcyr-test-script20452026/09/23 09:41:09 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3109650831/001/store/kpw49q3mi9i0fmn95q1qcsgg2gi9a6cj-pinned-file.txt narinfo_key=kpw49q3mi9i0fmn95q1qcsgg2gi9a6cj.narinfo20462026/09/23 09:41:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures20472026/09/23 09:41:09 INFO Garbage collection started20482026/09/23 09:41:09 INFO Aborted multipart uploads count=020492026/09/23 09:41:09 WARN Force mode enabled - objects will be deleted immediately without grace period20502026/09/23 09:41:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20512026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures20522026/09/23 09:41:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20532026/09/23 09:41:09 INFO Uploading 9mmgzqki96r04bwal3a726z0rlx9fzq7-shared-dep (136B)2054 client_integration_test.go:615: Found 1 dependencies (including self)2055=== NAME TestClientMultipleUploads2056 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2571435115/001/store/njrpnkbgz4bp8kxg8xfqfvdfrh9bqqaw-test-file-0.txt20572026/09/23 09:41:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20582026/09/23 09:41:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20592026/09/23 09:41:09 WARN Failed to register uploaded object key=9mmgzqki96r04bwal3a726z0rlx9fzq7.ls error="server returned 404: 404 page not found\n"20602026/09/23 09:41:09 INFO Signed narinfos id=2 count=120612026/09/23 09:41:09 INFO Uploading 1 narinfos20622026/09/23 09:41:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20632026/09/23 09:41:09 WARN Failed to register uploaded object key=9mmgzqki96r04bwal3a726z0rlx9fzq7.narinfo error="server returned 404: 404 page not found\n"20642026/09/23 09:41:09 INFO Completed upload id=220652026/09/23 09:41:09 INFO Upload complete. (60ms)20662026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures20672026/09/23 09:41:09 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20682026/09/23 09:41:09 INFO Uploading 9mmgzqki96r04bwal3a726z0rlx9fzq7-shared-dep (136B)20692026/09/23 09:41:09 INFO Uploading 0jh1wfxkihng1byh0lij6lip7dwfy328-top (224B)20702026/09/23 09:41:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20712026/09/23 09:41:09 WARN Failed to register uploaded object key=9mmgzqki96r04bwal3a726z0rlx9fzq7.ls error="server returned 404: 404 page not found\n"20722026/09/23 09:41:09 WARN Failed to register uploaded object key=0jh1wfxkihng1byh0lij6lip7dwfy328.ls error="server returned 404: 404 page not found\n"20732026/09/23 09:41:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20742026/09/23 09:41:09 INFO Signed narinfos id=1 count=120752026/09/23 09:41:09 WARN Failed to register uploaded object key=nar/0dm5r2mvm9dwlhfsp8hfjhmr5smi2vpxwmbbbc8c7njimkf8k0kc.nar.zst error="server returned 404: 404 page not found\n"20762026/09/23 09:41:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20772026/09/23 09:41:09 INFO Signed narinfos id=3 count=120782026/09/23 09:41:09 INFO Uploading 2 narinfos2079=== NAME TestClientIntegration2080 client_integration_test.go:286: Created store path: /build/TestClientIntegration1663618155/002/store/yp6cjj5c66y5c6m1k1ql1py1cfm49l6y-test-file.txt20812026/09/23 09:41:09 WARN Failed to register uploaded object key=0jh1wfxkihng1byh0lij6lip7dwfy328.narinfo error="server returned 404: 404 page not found\n"20822026/09/23 09:41:09 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20832026/09/23 09:41:09 WARN Failed to register uploaded object key=9mmgzqki96r04bwal3a726z0rlx9fzq7.narinfo error="server returned 404: 404 page not found\n"20842026/09/23 09:41:09 INFO Completed upload id=320852026/09/23 09:41:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20862026/09/23 09:41:09 INFO Completed upload id=120872026/09/23 09:41:09 INFO Upload complete. (159ms)2088=== NAME TestClientMultipleUploads2089 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2571435115/001/store/b1yfkmvwzvrmbg69n7aipmny5p8dgv10-test-file-1.txt2090=== NAME TestClientSharedPathCommittedMidPush2091 client_integration_test.go:680: Retrieved narinfo from S3:2092 StorePath: /build/TestClientSharedPathCommittedMidPush3059844656/001/store/9mmgzqki96r04bwal3a726z0rlx9fzq7-shared-dep2093 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2094 Compression: zstd2095 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822096 NarSize: 1362097 References: 2098 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2099 client_integration_test.go:680: Retrieved narinfo from S3:2100 StorePath: /build/TestClientSharedPathCommittedMidPush3059844656/001/store/0jh1wfxkihng1byh0lij6lip7dwfy328-top2101 URL: nar/0dm5r2mvm9dwlhfsp8hfjhmr5smi2vpxwmbbbc8c7njimkf8k0kc.nar.zst2102 Compression: zstd2103 NarHash: sha256:0dm5r2mvm9dwlhfsp8hfjhmr5smi2vpxwmbbbc8c7njimkf8k0kc2104 NarSize: 2242105 References: /build/TestClientSharedPathCommittedMidPush3059844656/001/store/9mmgzqki96r04bwal3a726z0rlx9fzq7-shared-dep2106 CA: text:sha256:0p146g7kk9k606zlczahp25yyz0lpjkjks78c03jblwpkfn4s0582107--- PASS: TestClientSharedPathCommittedMidPush (0.83s)21082026/09/23 09:41:09 INFO lead: released remote=192.0.2.1:123421092026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures21102026/09/23 09:41:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21112026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures21122026/09/23 09:41:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21132026/09/23 09:41:09 INFO Uploading mfapbsm5pzvw2zyivycj74di0mpabcyr-test-script (136B)2114=== NAME TestClientMultipleUploads2115 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2571435115/001/store/sgp32j30s0svb0zs4l7w05zi8cq6hikc-test-file-2.txt2116--- PASS: TestResurrectedObjectNotDeleted (0.60s)21172026/09/23 09:41:09 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"21182026/09/23 09:41:09 WARN Failed to register uploaded object key=mfapbsm5pzvw2zyivycj74di0mpabcyr.ls error="server returned 404: 404 page not found\n"21192026/09/23 09:41:09 WARN Failed to register uploaded object key=log/jb8dp68nkx4ld94wlmazdqbyjvy2n6jj-test-script.drv error="server returned 404: 404 page not found\n"21202026/09/23 09:41:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21212026/09/23 09:41:09 INFO Signed narinfos id=1 count=121222026/09/23 09:41:09 INFO Uploading 1 narinfos21232026/09/23 09:41:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21242026/09/23 09:41:09 WARN Failed to register uploaded object key=mfapbsm5pzvw2zyivycj74di0mpabcyr.narinfo error="server returned 404: 404 page not found\n"21252026/09/23 09:41:09 INFO Completed upload id=121262026/09/23 09:41:09 INFO Upload complete. (64ms)2127=== NAME TestClientWithDependencies2128 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2849821803/001/store) requires matching store prefix21292026/09/23 09:41:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21302026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures2131--- PASS: TestClientWithDependencies (0.84s)21322026/09/23 09:41:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21332026/09/23 09:41:09 WARN Refused reserved pin name=worker-x86_64-linux21342026/09/23 09:41:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21352026/09/23 09:41:09 INFO Received create pin request method=POST path=/api/pins/my-app21362026/09/23 09:41:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2137--- PASS: TestCreatePin_ReservedPins (0.70s)21382026/09/23 09:41:09 INFO lead: acquired remote=192.0.2.1:123421392026/09/23 09:41:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21402026/09/23 09:41:09 INFO Uploading yp6cjj5c66y5c6m1k1ql1py1cfm49l6y-test-file.txt (152B)21412026/09/23 09:41:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=387.66171ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21422026/09/23 09:41:09 INFO lead: released remote=192.0.2.1:12342143--- PASS: TestLeadElectsOneAndHandsOver (0.84s)21442026/09/23 09:41:09 WARN Failed to register uploaded object key=yp6cjj5c66y5c6m1k1ql1py1cfm49l6y.ls error="server returned 404: 404 page not found\n"21452026/09/23 09:41:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21462026/09/23 09:41:09 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"21472026/09/23 09:41:09 INFO Signed narinfos id=1 count=121482026/09/23 09:41:09 INFO Uploading 1 narinfos21492026/09/23 09:41:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21502026/09/23 09:41:09 WARN Failed to register uploaded object key=yp6cjj5c66y5c6m1k1ql1py1cfm49l6y.narinfo error="server returned 404: 404 page not found\n"2151--- PASS: TestObjectStatsTrigger (0.60s)21522026/09/23 09:41:09 INFO Completed upload id=121532026/09/23 09:41:09 INFO Upload complete. (64ms)21542026/09/23 09:41:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21552026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures21562026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures21572026/09/23 09:41:09 INFO Received uploads request method=POST path=/api/pending_closures21582026/09/23 09:41:09 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)21592026/09/23 09:41:09 INFO Uploading sgp32j30s0svb0zs4l7w05zi8cq6hikc-test-file-2.txt (160B)21602026/09/23 09:41:09 INFO Uploading b1yfkmvwzvrmbg69n7aipmny5p8dgv10-test-file-1.txt (160B)21612026/09/23 09:41:09 INFO Uploading njrpnkbgz4bp8kxg8xfqfvdfrh9bqqaw-test-file-0.txt (160B)21622026/09/23 09:41:09 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"21632026/09/23 09:41:09 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"21642026/09/23 09:41:09 WARN Failed to register uploaded object key=sgp32j30s0svb0zs4l7w05zi8cq6hikc.ls error="server returned 404: 404 page not found\n"21652026/09/23 09:41:09 WARN Failed to register uploaded object key=b1yfkmvwzvrmbg69n7aipmny5p8dgv10.ls error="server returned 404: 404 page not found\n"21662026/09/23 09:41:09 INFO All 1 paths already cached21672026/09/23 09:41:09 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"21682026/09/23 09:41:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21692026/09/23 09:41:09 WARN Failed to register uploaded object key=njrpnkbgz4bp8kxg8xfqfvdfrh9bqqaw.ls error="server returned 404: 404 page not found\n"21702026/09/23 09:41:09 INFO Signed narinfos id=2 count=121712026/09/23 09:41:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign21722026/09/23 09:41:09 INFO Signed narinfos id=3 count=12173=== NAME TestClientIntegration21742026/09/23 09:41:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign2175 client_integration_test.go:312: Retrieved narinfo from S3:2176 StorePath: /build/TestClientIntegration1663618155/002/store/yp6cjj5c66y5c6m1k1ql1py1cfm49l6y-test-file.txt2177 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2178 Compression: zstd2179 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12180 NarSize: 1522181 References: 2182 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk121832026/09/23 09:41:09 INFO Signed narinfos id=1 count=121842026/09/23 09:41:09 INFO Uploading 3 narinfos2185 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2186 client_integration_test.go:313: Decompressed .ls content (64 bytes):2187 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2188 client_integration_test.go:316: Testing garbage collection...21892026/09/23 09:41:09 WARN Failed to register uploaded object key=njrpnkbgz4bp8kxg8xfqfvdfrh9bqqaw.narinfo error="server returned 404: 404 page not found\n"21902026/09/23 09:41:09 WARN Failed to register uploaded object key=sgp32j30s0svb0zs4l7w05zi8cq6hikc.narinfo error="server returned 404: 404 page not found\n"21912026/09/23 09:41:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21922026/09/23 09:41:09 WARN Failed to register uploaded object key=b1yfkmvwzvrmbg69n7aipmny5p8dgv10.narinfo error="server returned 404: 404 page not found\n"21932026/09/23 09:41:09 INFO Received cleanup request method=DELETE path=/api/pending_closures21942026/09/23 09:41:09 INFO Aborted multipart uploads count=121952026/09/23 09:41:09 INFO Completed upload id=221962026/09/23 09:41:09 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete21972026/09/23 09:41:09 INFO Completed upload id=321982026/09/23 09:41:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21992026/09/23 09:41:09 INFO Completed upload id=122002026/09/23 09:41:09 INFO Upload complete. (74ms)2201=== NAME TestClientMultipleUploads2202 client_integration_test.go:369: Uploaded 3 paths in 108.837958ms2203--- PASS: TestMultipartCleanup (0.69s)2204--- PASS: TestClientMultipleUploads (0.90s)22052026/09/23 09:41:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures22062026/09/23 09:41:09 INFO Garbage collection started22072026/09/23 09:41:09 INFO Aborted multipart uploads count=022082026/09/23 09:41:09 WARN Force mode enabled - objects will be deleted immediately without grace period22092026/09/23 09:41:09 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22102026/09/23 09:41:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22112026/09/23 09:41:09 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2212=== NAME TestOrphanedObjectsGC2213 orphaned_objects_gc_test.go:290: GC Test Summary:2214 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2215 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2216 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2217 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2218 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2219--- PASS: TestOrphanedObjectsGC (0.89s)22202026/09/23 09:41:09 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=866.524448ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2221--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2222 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.11s)2223 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.10s)2224 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.58s)22252026/09/23 09:41:10 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=022262026/09/23 09:41:10 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.717704381s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22272026/09/23 09:41:10 INFO Vacuumed table table=pending_closures22282026/09/23 09:41:10 INFO Vacuumed table table=pending_objects22292026/09/23 09:41:10 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=022302026/09/23 09:41:10 INFO Vacuumed table table=multipart_uploads22312026/09/23 09:41:10 INFO Vacuumed table table=closures22322026/09/23 09:41:10 INFO Vacuumed table table=pending_closures22332026/09/23 09:41:10 INFO Vacuumed table table=objects22342026/09/23 09:41:10 INFO Vacuumed table table=pending_objects22352026/09/23 09:41:10 INFO Vacuumed table table=multipart_uploads22362026/09/23 09:41:10 INFO Vacuumed table table=closures22372026/09/23 09:41:10 INFO Vacuumed table table=objects2238=== NAME TestOrphanedObjectsGCStressTest2239 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2240 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion22412026/09/23 09:41:11 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02242=== NAME TestPinProtectsFromGC2243 client_integration_test.go:794: Pin successfully protected closure from garbage collection2244--- PASS: TestPinProtectsFromGC (2.89s)22452026/09/23 09:41:11 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02246=== NAME TestClientIntegration2247 client_integration_test.go:323: Objects in database after GC:2248 client_integration_test.go:323: Successfully deleted all objects with GC --force2249--- PASS: TestClientIntegration (2.86s)2250=== NAME TestOrphanedObjectsGCStressTest2251 orphaned_objects_gc_test.go:509: Stress test completed successfully:2252 orphaned_objects_gc_test.go:510: - Active objects preserved: 202253 orphaned_objects_gc_test.go:511: - Objects deleted: 2102254 orphaned_objects_gc_test.go:512: - Total GC'd: 2102255--- PASS: TestOrphanedObjectsGCStressTest (2.78s)22562026/09/23 09:41:12 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-config22572026/09/23 09:41:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.107856ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22582026/09/23 09:41:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=422.760295ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22592026/09/23 09:41:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=746.441686ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22602026/09/23 09:41:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.495350466s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22612026/09/23 09:41:13 WARN Rate limiter enabled after throttle name=s3-test rate=522622026/09/23 09:41:13 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2263=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2264 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102265 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002266--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.46s)22672026/09/23 09:41:15 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"22682026/09/23 09:41:15 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_closures22692026/09/23 09:41:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.240444ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22702026/09/23 09:41:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.842385ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22712026/09/23 09:41:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=775.284975ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22722026/09/23 09:41:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.72740563s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2273--- PASS: TestClientErrorHandling (0.00s)2274 --- PASS: TestClientErrorHandling/InvalidStorePath (0.49s)2275 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.57s)2276 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.55s)2277PASS22782026-09-23 09:41:18.772 UTC [129] LOG: received smart shutdown request22792026-09-23 09:41:18.777 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122802026-09-23 09:41:18.790 UTC [134] LOG: shutting down22812026-09-23 09:41:18.790 UTC [134] LOG: checkpoint starting: shutdown immediate22822026-09-23 09:41:19.614 UTC [134] LOG: checkpoint complete: wrote 11560 buffers (70.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.217 s, sync=0.586 s, total=0.824 s; sync files=19406, longest=0.008 s, average=0.001 s; distance=264840 kB, estimate=264840 kB; lsn=0/11A07D80, redo lsn=0/11A07D8022832026-09-23 09:41:19.712 UTC [129] LOG: database system is shut down2284Running OIDC tests...2285=== RUN TestAudienceForIssuer2286=== PAUSE TestAudienceForIssuer2287=== RUN TestGlobMatch2288=== PAUSE TestGlobMatch2289=== RUN TestValidateToken_ValidToken2290=== PAUSE TestValidateToken_ValidToken2291=== RUN TestValidateToken_WrongAudience2292=== PAUSE TestValidateToken_WrongAudience2293=== RUN TestValidateToken_Expired2294=== PAUSE TestValidateToken_Expired2295=== RUN TestValidateToken_BoundClaimsMismatch2296=== PAUSE TestValidateToken_BoundClaimsMismatch2297=== RUN TestValidateToken_BoundSubjectMismatch2298=== PAUSE TestValidateToken_BoundSubjectMismatch2299=== RUN TestValidateToken_MultipleProviders2300=== PAUSE TestValidateToken_MultipleProviders2301=== RUN TestValidateToken_NoMatchingProvider2302=== PAUSE TestValidateToken_NoMatchingProvider2303=== RUN TestValidateToken_KubernetesServiceAccount2304=== PAUSE TestValidateToken_KubernetesServiceAccount2305=== RUN TestNewValidator_KubernetesRequiresCA2306=== PAUSE TestNewValidator_KubernetesRequiresCA2307=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2308=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2309=== RUN TestPins_ReservedForMatchingRule2310=== PAUSE TestPins_ReservedForMatchingRule2311=== RUN TestPins_TopLevelShorthand2312=== PAUSE TestPins_TopLevelShorthand2313=== RUN TestPins_ConfigValidation2314=== PAUSE TestPins_ConfigValidation2315=== RUN TestScopes_LegacyProviderDefaultsToWrite2316=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2317=== RUN TestScopes_Rules2318=== PAUSE TestScopes_Rules2319=== RUN TestScopes_ConfigValidation2320=== PAUSE TestScopes_ConfigValidation2321=== CONT TestAudienceForIssuer2322=== CONT TestValidateToken_BoundClaimsMismatch2323--- PASS: TestAudienceForIssuer (0.00s)2324=== CONT TestValidateToken_ValidToken2325=== CONT TestValidateToken_KubernetesServiceAccount2326=== CONT TestValidateToken_WrongAudience2327=== CONT TestGlobMatch2328=== RUN TestGlobMatch/foo_foo2329=== PAUSE TestGlobMatch/foo_foo2330=== RUN TestGlobMatch/foo_bar2331=== PAUSE TestGlobMatch/foo_bar2332=== RUN TestGlobMatch/*_2333=== PAUSE TestGlobMatch/*_2334=== RUN TestGlobMatch/*_anything2335=== PAUSE TestGlobMatch/*_anything2336=== RUN TestGlobMatch/foo*_foo2337=== CONT TestValidateToken_Expired2338=== CONT TestValidateToken_MultipleProviders2339=== PAUSE TestGlobMatch/foo*_foo2340=== RUN TestGlobMatch/foo*_foobar2341=== PAUSE TestGlobMatch/foo*_foobar2342=== RUN TestGlobMatch/foo*_bar2343=== PAUSE TestGlobMatch/foo*_bar2344=== CONT TestValidateToken_NoMatchingProvider2345=== CONT TestValidateToken_BoundSubjectMismatch2346=== CONT TestPins_ConfigValidation2347=== CONT TestScopes_ConfigValidation2348=== CONT TestScopes_Rules2349=== CONT TestScopes_LegacyProviderDefaultsToWrite2350=== CONT TestPins_ReservedForMatchingRule2351=== CONT TestPins_TopLevelShorthand2352--- PASS: TestPins_ConfigValidation (0.00s)2353=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2354=== CONT TestNewValidator_KubernetesRequiresCA2355--- PASS: TestScopes_ConfigValidation (0.00s)2356=== RUN TestGlobMatch/*bar_bar2357=== PAUSE TestGlobMatch/*bar_bar2358=== RUN TestGlobMatch/*bar_foobar2359=== PAUSE TestGlobMatch/*bar_foobar2360=== RUN TestGlobMatch/*bar_foo2361=== PAUSE TestGlobMatch/*bar_foo2362=== RUN TestGlobMatch/foo*bar_foobar2363=== PAUSE TestGlobMatch/foo*bar_foobar2364=== RUN TestGlobMatch/foo*bar_foo123bar2365=== PAUSE TestGlobMatch/foo*bar_foo123bar2366=== RUN TestGlobMatch/foo*bar_foobarbaz2367=== PAUSE TestGlobMatch/foo*bar_foobarbaz2368=== RUN TestGlobMatch/*/*_foo/bar2369=== PAUSE TestGlobMatch/*/*_foo/bar2370=== RUN TestGlobMatch/*/*_foo2371=== PAUSE TestGlobMatch/*/*_foo2372=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2373=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2374=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02375=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02376=== RUN TestGlobMatch/refs/*/main_refs/heads/main2377=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2378=== RUN TestGlobMatch/fo?_foo2379=== PAUSE TestGlobMatch/fo?_foo2380=== RUN TestGlobMatch/fo?_fo2381=== PAUSE TestGlobMatch/fo?_fo2382=== RUN TestGlobMatch/fo?_fooo2383=== PAUSE TestGlobMatch/fo?_fooo2384=== RUN TestGlobMatch/?oo_foo2385=== PAUSE TestGlobMatch/?oo_foo2386=== RUN TestGlobMatch/?oo_boo2387=== PAUSE TestGlobMatch/?oo_boo2388=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2389=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2390=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2391=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2392=== CONT TestGlobMatch/foo_foo2393=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2394=== CONT TestGlobMatch/?oo_boo2395=== CONT TestGlobMatch/?oo_foo2396=== CONT TestGlobMatch/fo?_fooo2397=== CONT TestGlobMatch/fo?_fo2398=== CONT TestGlobMatch/fo?_foo2399=== CONT TestGlobMatch/refs/*/main_refs/heads/main2400=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02401=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2402=== CONT TestGlobMatch/*/*_foo2403=== CONT TestGlobMatch/*bar_bar2404=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2405=== CONT TestGlobMatch/*bar_foo2406=== CONT TestGlobMatch/foo*bar_foobar2407=== CONT TestGlobMatch/*bar_foobar2408=== CONT TestGlobMatch/foo*_bar2409=== CONT TestGlobMatch/foo*_foobar2410=== CONT TestGlobMatch/foo*_foo2411=== CONT TestGlobMatch/*_anything2412=== CONT TestGlobMatch/*_2413=== CONT TestGlobMatch/foo_bar2414=== CONT TestGlobMatch/foo*bar_foo123bar2415=== CONT TestGlobMatch/*/*_foo/bar2416=== CONT TestGlobMatch/foo*bar_foobarbaz2417--- PASS: TestGlobMatch (0.01s)2418 --- PASS: TestGlobMatch/foo_foo (0.00s)2419 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2420 --- PASS: TestGlobMatch/?oo_boo (0.00s)2421 --- PASS: TestGlobMatch/?oo_foo (0.00s)2422 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2423 --- PASS: TestGlobMatch/fo?_fo (0.00s)2424 --- PASS: TestGlobMatch/fo?_foo (0.00s)2425 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2426 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2427 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2428 --- PASS: TestGlobMatch/*/*_foo (0.00s)2429 --- PASS: TestGlobMatch/*bar_bar (0.00s)2430 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2431 --- PASS: TestGlobMatch/*bar_foo (0.00s)2432 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2433 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2434 --- PASS: TestGlobMatch/foo*_bar (0.00s)2435 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2436 --- PASS: TestGlobMatch/foo*_foo (0.00s)2437 --- PASS: TestGlobMatch/*_anything (0.00s)2438 --- PASS: TestGlobMatch/*_ (0.00s)2439 --- PASS: TestGlobMatch/foo_bar (0.00s)2440 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2441 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2442 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)24432026/09/23 09:41:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42747/oidc2444--- PASS: TestPins_TopLevelShorthand (0.03s)24452026/09/23 09:41:20 http: TLS handshake error from 127.0.0.1:56266: remote error: tls: bad certificate2446--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)24472026/09/23 09:41:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44915/oidc2448--- PASS: TestValidateToken_Expired (0.10s)24492026/09/23 09:41:20 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3557924502026/09/23 09:41:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36397/oidc2451--- PASS: TestValidateToken_KubernetesServiceAccount (0.12s)2452--- PASS: TestValidateToken_WrongAudience (0.12s)24532026/09/23 09:41:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34581/oidc2454--- PASS: TestPins_ReservedForMatchingRule (0.13s)24552026/09/23 09:41:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45121/oidc2456--- PASS: TestValidateToken_BoundClaimsMismatch (0.17s)24572026/09/23 09:41:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45197/oidc2458--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.21s)24592026/09/23 09:41:20 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324602026/09/23 09:41:20 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40247/oidc24612026/09/23 09:41:20 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35403/oidc2462--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.26s)2463--- PASS: TestValidateToken_MultipleProviders (0.26s)24642026/09/23 09:41:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39805/oidc2465--- PASS: TestValidateToken_BoundSubjectMismatch (0.32s)24662026/09/23 09:41:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39569/oidc2467--- PASS: TestValidateToken_ValidToken (0.37s)24682026/09/23 09:41:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43581/oidc2469--- PASS: TestValidateToken_NoMatchingProvider (0.42s)24702026/09/23 09:41:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36949/oidc2471--- PASS: TestScopes_Rules (0.62s)2472PASS2473Running hook tests...2474=== RUN TestSendPathsEmpty2475=== PAUSE TestSendPathsEmpty2476=== RUN TestQueueEnqueueAndFetch2477=== PAUSE TestQueueEnqueueAndFetch2478=== RUN TestQueueDeduplication2479=== PAUSE TestQueueDeduplication2480=== RUN TestQueueRemove2481=== PAUSE TestQueueRemove2482=== RUN TestQueueFetchBatchLimit2483=== PAUSE TestQueueFetchBatchLimit2484=== RUN TestQueueRetryMovesToBack2485=== PAUSE TestQueueRetryMovesToBack2486=== RUN TestQueueFetchRemoveLifecycle2487=== PAUSE TestQueueFetchRemoveLifecycle2488=== RUN TestQueueConcurrentWriters2489=== PAUSE TestQueueConcurrentWriters2490=== RUN TestQueueRemoveLargeClosure2491=== PAUSE TestQueueRemoveLargeClosure2492=== RUN TestServerClientIntegration2493=== PAUSE TestServerClientIntegration2494=== RUN TestServerQueueError2495=== PAUSE TestServerQueueError2496=== RUN TestGetListenerSocketActivation2497 server_test.go:210: === RUN TestGetListenerSocketActivation2498 --- PASS: TestGetListenerSocketActivation (0.00s)2499 PASS2500 2501--- PASS: TestGetListenerSocketActivation (0.01s)2502=== RUN TestDrainIsolatesPoisonPath2503=== PAUSE TestDrainIsolatesPoisonPath2504=== RUN TestRunNotBlockedByPoisonHead2505=== PAUSE TestRunNotBlockedByPoisonHead2506=== RUN TestDrainGivesUpWhenServerDown2507=== PAUSE TestDrainGivesUpWhenServerDown2508=== RUN TestFailedPathPrunedByLaterClosure2509=== PAUSE TestFailedPathPrunedByLaterClosure2510=== RUN TestWorkerUploadsAndRemoves2511=== PAUSE TestWorkerUploadsAndRemoves2512=== RUN TestWorkerSkipsGCdPaths2513=== PAUSE TestWorkerSkipsGCdPaths2514=== RUN TestWorkerPrunesClosureDeps2515=== PAUSE TestWorkerPrunesClosureDeps2516=== RUN TestDrainTimeout2517=== PAUSE TestDrainTimeout2518=== CONT TestSendPathsEmpty2519=== CONT TestServerQueueError2520=== CONT TestDrainGivesUpWhenServerDown2521--- PASS: TestSendPathsEmpty (0.00s)2522=== CONT TestQueueFetchBatchLimit2523=== CONT TestQueueRemove2524=== CONT TestQueueDeduplication2525=== CONT TestQueueEnqueueAndFetch2526=== CONT TestWorkerUploadsAndRemoves2527=== CONT TestDrainTimeout2528=== CONT TestWorkerPrunesClosureDeps25292026/09/23 09:41:21 ERROR Failed to queue paths error="permission denied" count=12530=== CONT TestQueueRetryMovesToBack2531=== CONT TestWorkerSkipsGCdPaths2532--- PASS: TestServerQueueError (0.00s)2533=== CONT TestServerClientIntegration2534=== CONT TestQueueRemoveLargeClosure2535=== CONT TestFailedPathPrunedByLaterClosure2536=== CONT TestQueueConcurrentWriters2537=== CONT TestQueueFetchRemoveLifecycle2538=== CONT TestDrainIsolatesPoisonPath2539=== CONT TestRunNotBlockedByPoisonHead2540--- PASS: TestServerClientIntegration (0.00s)25412026/09/23 09:41:21 INFO Uploading batch count=125422026/09/23 09:41:21 ERROR Upload failed error="upload failed" count=125432026/09/23 09:41:21 INFO Uploading batch count=225442026/09/23 09:41:21 INFO Upload queue status pending=225452026/09/23 09:41:21 INFO Uploading batch count=425462026/09/23 09:41:21 ERROR Upload failed error="upload failed" count=42547--- PASS: TestQueueFetchBatchLimit (0.01s)25482026/09/23 09:41:21 INFO Uploading batch count=125492026/09/23 09:41:21 INFO Upload queue status pending=225502026/09/23 09:41:21 INFO Uploading batch count=125512026/09/23 09:41:21 INFO Upload queue status pending=32552--- PASS: TestQueueDeduplication (0.01s)25532026/09/23 09:41:21 INFO Uploading batch count=125542026/09/23 09:41:21 INFO Uploading batch count=225552026/09/23 09:41:21 ERROR Upload failed error="upload failed" count=125562026/09/23 09:41:21 INFO Uploading batch count=225572026/09/23 09:41:21 ERROR Upload failed error="upload failed" count=225582026/09/23 09:41:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3564471925/002/a25592026/09/23 09:41:21 INFO Upload queue status pending=22560--- PASS: TestQueueEnqueueAndFetch (0.01s)25612026/09/23 09:41:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1070491330/002/nonexistent25622026/09/23 09:41:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2365451075/002/bbb25632026/09/23 09:41:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3564471925/002/b25642026/09/23 09:41:21 INFO Uploading batch count=12565--- PASS: TestQueueFetchRemoveLifecycle (0.01s)25662026/09/23 09:41:21 INFO Uploading batch count=12567--- PASS: TestQueueRemove (0.02s)25682026/09/23 09:41:21 INFO Uploading batch count=225692026/09/23 09:41:21 ERROR Upload failed error="upload failed" count=225702026/09/23 09:41:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3564471925/002/c25712026/09/23 09:41:21 INFO Uploading batch count=125722026/09/23 09:41:21 ERROR Upload failed error="upload failed" count=12573--- PASS: TestQueueRetryMovesToBack (0.02s)25742026/09/23 09:41:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3564471925/002/d25752026/09/23 09:41:21 INFO Uploading batch count=125762026/09/23 09:41:21 ERROR Upload failed error="upload failed" count=125772026/09/23 09:41:21 INFO Uploading batch count=125782026/09/23 09:41:21 ERROR Upload failed error="upload failed" count=125792026/09/23 09:41:21 ERROR Drain finished with paths left in queue remaining=125802026/09/23 09:41:21 INFO Uploading batch count=225812026/09/23 09:41:21 ERROR Upload failed error="upload failed" count=225822026/09/23 09:41:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3564471925/002/e2583--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25842026/09/23 09:41:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3564471925/002/f25852026/09/23 09:41:21 ERROR Drain finished with paths left in queue remaining=102586--- PASS: TestDrainIsolatesPoisonPath (0.02s)2587--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2588--- PASS: TestWorkerUploadsAndRemoves (0.03s)2589--- PASS: TestWorkerPrunesClosureDeps (0.03s)2590--- PASS: TestWorkerSkipsGCdPaths (0.03s)25912026/09/23 09:41:21 ERROR Upload failed error="context deadline exceeded" count=225922026/09/23 09:41:21 ERROR Drain finished with paths left in queue remaining=42593--- PASS: TestDrainTimeout (0.21s)2594--- PASS: TestQueueConcurrentWriters (0.21s)2595--- PASS: TestQueueRemoveLargeClosure (0.21s)25962026/09/23 09:41:22 INFO Uploading batch count=125972026/09/23 09:41:22 INFO Uploading batch count=125982026/09/23 09:41:22 INFO Uploading batch count=125992026/09/23 09:41:22 ERROR Upload failed error="upload failed" count=126002026/09/23 09:41:22 INFO Uploading batch count=126012026/09/23 09:41:22 ERROR Upload failed error="upload failed" count=126022026/09/23 09:41:22 INFO Uploading batch count=126032026/09/23 09:41:22 ERROR Upload failed error="upload failed" count=126042026/09/23 09:41:22 INFO Uploading batch count=126052026/09/23 09:41:22 ERROR Upload failed error="upload failed" count=126062026/09/23 09:41:22 ERROR Drain finished with paths left in queue remaining=12607--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2608PASS