2025-10-26T18:07:10.684088Z node 11 :METADATA_PROVIDER WARN: fline=table_exists.cpp:54;actor=TTableExistsActor;event=undelivered;self_id=[11:7565593613937020279:7306];send_to=[0:7307199536658146131:7762515];
2025-10-26T18:07:10.688794Z node 11 :METADATA_PROVIDER ERROR: fline=accessor_snapshot_base.cpp:68;action=cannot detect path existence;path=//Root/.metadata/initialization/migrations;error=scheme_cache_undelivered_message;
2025-10-26T18:07:10.789985Z node 11 :PQ_READ_PROXY DEBUG: Direct read cache created
test_client.cpp: SetPath # /home/runner/.ya/build/build_root/70hy/000519/r3tmp/tmpa3Ul8C/pdisk_1.dat
2025-10-26T18:07:11.126074Z node 11 :IMPORT WARN: Table profiles were not loaded
2025-10-26T18:07:11.173095Z node 11 :HIVE WARN: HIVE#72057594037968897 Node(11, (0,0,0,0)) VolatileState: Unknown -> Disconnected
2025-10-26T18:07:11.173229Z node 11 :HIVE WARN: HIVE#72057594037968897 Node(11, (0,0,0,0)) VolatileState: Disconnected -> Connecting
2025-10-26T18:07:11.175590Z node 11 :HIVE WARN: HIVE#72057594037968897 Node(11, (0,0,0,0)) VolatileState: Connecting -> Connected
TServer::EnableGrpc on GrpcPort 15705, node 11
2025-10-26T18:07:11.242683Z node 11 :NET_CLASSIFIER WARN: distributable config is empty, broken or outdated, will use file: /home/runner/.ya/build/build_root/70hy/000519/r3tmp/yandexkOovyM.tmp
2025-10-26T18:07:11.242717Z node 11 :NET_CLASSIFIER WARN: will try to initialize from file: /home/runner/.ya/build/build_root/70hy/000519/r3tmp/yandexkOovyM.tmp
2025-10-26T18:07:11.242896Z node 11 :NET_CLASSIFIER WARN: successfully initialized from file: /home/runner/.ya/build/build_root/70hy/000519/r3tmp/yandexkOovyM.tmp
2025-10-26T18:07:11.243074Z node 11 :NET_CLASSIFIER ERROR: got bad distributable configuration
2025-10-26T18:07:11.316847Z INFO: TTestServer started on Port 1494 GrpcPort 15705
TClient is connected to server localhost:1494
PQClient connected to localhost:15705
WaitRootIsUp 'Root'...
TClient::Ls request: Root
TClient::Ls response: Status: 1
StatusCode: SUCCESS
SchemeStatus: 0
PathDescription {
  Self {
    Name: "Root"
    PathId: 1
    SchemeshardId: 72057594046644480
    PathType: EPathTypeDir
    CreateFinished: true
    CreateTxId: 1
    CreateStep: 0
    ParentPathId: 1
    PathState: EPathStateNoChanges
    Owner: "root@builtin"
    ACL: ""
    EffectiveACL: ""
    PathVersion: 2
    PathSubType: EPathSubTypeEmpty
    Version {
      GeneralVersion: 2
      ACLVersion: 0
      EffectiveACLVersion: 0
      UserAttrsVersion: 1
      ChildrenVersion: 1
      SubDomainVersion: 0
      SecurityStateVersion: 0
    }
  }
  Children {
    Name: ".sys"
    PathId: 18446744073709551615
    SchemeshardId: 72057594046644480
    PathType: EPathTypeDir
    CreateFinished: true
    CreateTxId: 0
    CreateStep: 0
    ParentPathId: 18446744073709551615
  }
  DomainDescription {
    SchemeShardId_Depricated: 72057594046644480
    PathId_Depricated: 1
    ProcessingParams {
      Version: 0
      PlanResolution: 7
      Coo...
(TRUNCATED)
WaitRootIsUp 'Root' success.
2025-10-26T18:07:11.595132Z node 11 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpAlterSubDomain, opId: 281474976710657:0, at schemeshard:  72057594046644480
waiting...
waiting...
2025-10-26T18:07:11.621129Z node 11 :FLAT_TX_SCHEMESHARD WARN: NotifyTxCompletion, unknown transaction, txId: 281474976710658, at schemeshard: 72057594046644480
2025-10-26T18:07:11.629910Z node 11 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976710659:0, at schemeshard:  72057594046644480
waiting...
waiting...
waiting...
2025-10-26T18:07:15.619690Z node 11 :KQP_COMPILE_ACTOR ERROR: Compilation failed, self: [11:7565593635411857477:4257], status: SCHEME_ERROR, issues: <main>: Error: Type annotation, code: 1030
    <main>:3:16: Error: At function: KiReadTable!
        <main>:3:16: Error: Cannot find table 'db.[/Root/PQ/Config/V2/Cluster]' because it does not exist or you do not have access permissions. Please check correctness of table path and user permissions., code: 2003
2025-10-26T18:07:15.622912Z node 11 :KQP_SESSION WARN: SessionId: ydb://session/3?node_id=11&id=MjEwMzNjMzktZjU0YzZiZmMtYTI4N2ZhMWYtYmRiYzdmOTc=, ActorId: [11:7565593635411857474:4267], ActorState: ExecuteState, TraceId: 01k8gv7zkz70435ysv9cmrt58v, ReplyQueryCompileError, status SCHEME_ERROR remove tx with tx_id: 
2025-10-26T18:07:15.624131Z node 11 :PERSQUEUE_CLUSTER_TRACKER ERROR: failed to list clusters: { Response { QueryIssues { message: "Type annotation" issue_code: 1030 severity: 1 issues { position { row: 3 column: 16 } message: "At function: KiReadTable!" end_position { row: 3 column: 16 } severity: 1 issues { position { row: 3 column: 16 } message: "Cannot find table \'db.[/Root/PQ/Config/V2/Cluster]\' because it does not exist or you do not have access permissions. Please check correctness of table path and user permissions." end_position { row: 3 column: 16 } issue_code: 2003 severity: 1 } } } TxMeta { } } YdbStatus: SCHEME_ERROR ConsumedRu: 1 }
2025-10-26T18:07:15.657442Z node 11 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976710662:0, at schemeshard:  72057594046644480
2025-10-26T18:07:15.684001Z node 11 :METADATA_PROVIDER ERROR: fline=table_exists.cpp:59;actor=TTableExistsActor;event=timeout;self_id=[11:7565593613937020279:7306];send_to=[0:7307199536658146131:7762515];
2025-10-26T18:07:15.684113Z node 11 :METADATA_PROVIDER ERROR: fline=accessor_snapshot_base.cpp:68;action=cannot detect path existence;path=//Root/.metadata/initialization/migrations;error=timeout;
2025-10-26T18:07:15.727865Z node 11 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976710663:0, at schemeshard:  72057594046644480
2025-10-26T18:07:15.895189Z node 11 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976710664:0, at schemeshard:  72057594046644480
=== Init DC: UPSERT INTO `/Root/PQ/Config/V2/Cluster` (name, balancer, local, enabled, weight) VALUES ("dc1", "localhost", true, true, 1000), ("dc2", "dc2.logbroker.yandex.net", false, true, 1000);
2025-10-26T18:07:16.300473Z node 11 :KQP_EXECUTER ERROR: TxId: 281474976710665. Ctx: { TraceId: 01k8gv801g09xrcsk2e3pmznfs, Database: , DatabaseId: /Root, SessionId: ydb://session/3?node_id=11&id=MjY2YTgyYTQtZjkyZmJiZTAtM2M1MTQ4YzQtNjg1MjZjNDg=, CurrentExecutionId: , CustomerSuppliedId: , PoolId: }. Database not set, use /Root
=== CheckClustersList. Subcribe to ClusterTracker from [11:7565593639706825064:12291] 
=== CheckClustersList. Ok
PQ Client: create topic: rt3.dc1--topic1 with 2 partitions
CallPersQueueGRPC request to localhost:15705
MetaRequest {
  CmdGetTopicMetadata {
    Topic: "rt3.dc1--topic1"
  }
}
CallPersQueueGRPC response:
Status: 128
ErrorReason: "the following topics are not created: rt3.dc1--topic1, Marker# PQ95"
ErrorCode: UNKNOWN_TOPIC
2025-10-26T18:07:22.616469Z node 11 :PERSQUEUE INFO: proxy answer <none>
CallPersQueueGRPC request to localhost:15705
MetaRequest {
  CmdCreateTopic {
    Topic: "rt3.dc1--topic1"
    NumPartitions: 2
    Config {
      PartitionConfig {
        LifetimeSeconds: 86400
        LowWatermark: 8388608
        SourceIdLifetimeSeconds: 86400
        WriteSpeedInBytesPerSecond: 20000000
        BurstSize: 20000000
        SourceIdMaxCounts: 6000000
      }
      LocalDC: true
      ReadRules: "user"
      ReadFromTimestampsMs: 0
      ConsumerFormatVersions: 0
      ConsumerCodecs {
      }
      Codecs {
        Ids: 0
        Ids: 1
        Ids: 2
        Codecs: "raw"
        Codecs: "gzip"
        Codecs: "lzop"
      }
      ReadRuleVersions: 0
    }
  }
}
CallPersQueueGRPC response:
Status: 129
ProxyErrorCode: 53
SchemeStatus: 1
FlatTxId {
  TxId: 281474976710679
  SchemeShardTabletId: 72057594046644480
  PathId: 9
}
ErrorCode: OK
AddTopic: rt3.dc1--topic1
===Run query:``DECLARE $version as Int64; DECLARE $path AS Utf8; DECLARE $cluster as Utf8; UPSERT INTO `/Root/PQ/Config/V2/Topics` (path, dc) VALUES ($path, $cluster); UPSERT INTO `/Root/PQ/Config/V2/Versions` (name, version) VALUES ("Topics", $version);`` with topic = topic1, dc = dc1
2025-10-26T18:07:22.647329Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvInterconnect::TEvNodeInfo
2025-10-26T18:07:22.647667Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-10-26T18:07:22.648428Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-10-26T18:07:22.648631Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] doesn't have tx info
2025-10-26T18:07:22.648667Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-10-26T18:07:22.648698Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] no config, start with empty partitions and default config
2025-10-26T18:07:22.648729Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Txs.size=0, PlannedTxs.size=0
2025-10-26T18:07:22.648767Z node 11 :PERSQUEUE NOTICE: Tablet 72075186224037892 disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-10-26T18:07:22.648805Z node 11 :PERSQUEUE INFO: Tablet 72075186224037892 doesn't have tx writes info
2025-10-26T18:07:22.648864Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic  pipe [11:7565593665476629295:8454] connected; active server actors: 1
2025-10-26T18:07:22.649217Z node 11 :PERSQUEUE_READ_BALANCER DEBUG: balancer: [72075186224037893] topic rt3.dc1--topic1 updating configuration. Deleted partitions []. Added partitions [1, 0]
2025-10-26T18:07:22.649792Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server connected, pipe [11:7565593665476629293:8453], now have 1 active actors on pipe
2025-10-26T18:07:22.650275Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7565593613937020559 RawX2: 47244652602 } TxId: 281474976710679 Config { TabletConfig { PartitionConfig { LifetimeSeconds: 86400 LowWatermark: 8388608 SourceIdLifetimeSeconds: 86400 WriteSpeedInBytesPerSecond: 20000000 BurstSize: 20000000 TotalPartitions: 2 SourceIdMaxCounts: 6000000 } PartitionIds: 1 PartitionIds: 0 TopicName: "rt3.dc1--topic1" Version: 0 LocalDC: true ReadRules: "user" ReadFromTimestampsMs: 0 ConsumerFormatVersions: 0 ConsumerCodecs { } Codecs { Ids: 0 Ids: 1 Ids: 2 Codecs: "raw" Codecs: "gzip" Codecs: "lzop" } ReadRuleVersions: 0 TopicPath: "/Root/PQ/rt3.dc1--topic1" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 1 Status: Active CreateVersion: 1 TabletId: 0 } Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } } }
2025-10-26T18:07:22.650419Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Propose TxId 281474976710679, WriteId (empty maybe)
2025-10-26T18:07:22.650459Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state UNKNOWN
2025-10-26T18:07:22.650481Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State UNKNOWN
2025-10-26T18:07:22.650511Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] schedule TEvProposeTransactionResult(PREPARED)
2025-10-26T18:07:22.650550Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState PREPARING
2025-10-26T18:07:22.650622Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] write key for TxId 281474976710679
2025-10-26T18:07:22.651077Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] save tx TxId: 281474976710679 State: PREPARED MinStep: 1761502042643 MaxStep: 18446744073709551615 Kind: KIND_CONFIG TabletConfig { PartitionConfig { LifetimeSeconds: 86400 LowWatermark: 8388608 SourceIdLifetimeSeconds: 86400 WriteSpeedInBytesPerSecond: 20000000 BurstSize: 20000000 TotalPartitions: 2 SourceIdMaxCounts: 6000000 } PartitionIds: 1 PartitionIds: 0 TopicName: "rt3.dc1--topic1" Version: 0 LocalDC: true ReadRules: "user" ReadFromTimestampsMs: 0 ConsumerFormatVersions: 0 ConsumerCodecs { } Codecs { Ids: 0 Ids: 1 Ids: 2 Codecs: "raw" Codecs: "gzip" Codecs: "lzop" } ReadRuleVersions: 0 TopicPath: "/Root/PQ/rt3.dc1--topic1" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 1 Status: Active CreateVersion: 1 TabletId: 0 } Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 Consumers { Name: "user" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } Version: 0 Generation: 0 Important: false } } BootstrapConfig { } SourceActor { RawX1: 7565593613937020559 RawX2: 47244652602 }
2025-10-26T18:07:22.651241Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-10-26T18:07:22.651537Z node 11 :PERSQUEUE_READ_BALANCER DEBUG: Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-10-26T18:07:22.651634Z node 11 :PERSQUEUE_READ_BALANCER DEBUG: BALANCER INIT DONE for rt3.dc1--topic1: (0, 72075186224037892) (1, 72075186224037892) 
2025-10-26T18:07:22.652445Z node 11 :PERSQUEUE_READ_BALANCER DEBUG: tablet 72075186224037893 topic rt3.dc1--topic1 TEvClientConnected TabletId 72075186224037892, NodeId 11, Generation 1
2025-10-26T18:07:22.652492Z node 11 :PERSQUEUE_READ_BALANCER DEBUG: tablet 72075186224037893 topic rt3.dc1--topic1 TEvClientConnected TabletId 72057594046644480, NodeId 11, Generation 2
2025-10-26T18:07:22.652533Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server connected, pipe [11:7565593665476629341:2044], now have 1 active actors on pipe
2025-10-26T18:07:22.652707Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-10-26T18:07:22.652743Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARING
2025-10-26T18:07:22.652775Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State PREPARING
2025-10-26T18:07:22.652795Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState PREPARED
2025-10-26T18:07:22.654205Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037892 TxId: 281474976710679
2025-10-26T18:07:22.663121Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server connected, pipe [11:7565593665476629351:8406], now have 1 active actors on pipe
2025-10-26T18:07:22.663302Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976710679 AckTo { RawX1: 7565593618231988003 RawX2: 47244648504 } } Step: 1761502042699 MediatorID: 72057594046382081 TabletID: 72075186224037892
2025-10-26T18:07:22.663368Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARED
2025-10-26T18:07:22.663393Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State PREPARED
2025-10-26T18:07:22.663420Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState PLANNING
2025-10-26T18:07:22.663460Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] PlanStep 1761502042699, PlanTxId 281474976710679
2025-10-26T18:07:22.663513Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] write key for TxId 281474976710679
2025-10-26T18:07:22.664009Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] save tx TxId: 281474976710679 State: PLANNED MinStep: 1761502042643 MaxStep: 18446744073709551615 Step: 1761502042699 Kind: KIND_CONFIG TabletConfig { PartitionConfig { LifetimeSeconds: 86400 LowWatermark: 8388608 SourceIdLifetimeSeconds: 86400 WriteSpeedInBytesPerSecond: 20000000 BurstSize: 20000000 TotalPartitions: 2 SourceIdMaxCounts: 6000000 } PartitionIds: 1 PartitionIds: 0 TopicName: "rt3.dc1--topic1" Version: 0 LocalDC: true ReadRules: "user" ReadFromTimestampsMs: 0 ConsumerFormatVersions: 0 ConsumerCodecs { } Codecs { Ids: 0 Ids: 1 Ids: 2 Codecs: "raw" Codecs: "gzip" Codecs: "lzop" } ReadRuleVersions: 0 TopicPath: "/Root/PQ/rt3.dc1--topic1" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 1 Status: Active CreateVersion: 1 TabletId: 0 } Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 Consumers { Name: "user" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } Version: 0 Generation: 0 Important: false } } BootstrapConfig { } SourceActor { RawX1: 7565593613937020559 RawX2: 47244652602 }
2025-10-26T18:07:22.664184Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-10-26T18:07:22.679024Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-10-26T18:07:22.679097Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state PLANNING
2025-10-26T18:07:22.679122Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State PLANNING
2025-10-26T18:07:22.679151Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState PLANNED
2025-10-26T18:07:22.679212Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 moved from PLANNING to PLANNED
2025-10-26T18:07:22.679232Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxQueue.size 1
2025-10-26T18:07:22.679255Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] New ExecStep 1761502042699, ExecTxId 281474976710679
2025-10-26T18:07:22.680890Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState CALCULATING
2025-10-26T18:07:22.680929Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 moved from PLANNED to CALCULATING
2025-10-26T18:07:22.681014Z node 11 :PERSQUEUE DEBUG: Initializing topic 'rt3.dc1--topic1' partition 1. Step TInitConfigStep
2025-10-26T18:07:22.681085Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 1, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-10-26T18:07:22.681517Z node 11 :PERSQUEUE DEBUG: Initializing topic 'rt3.dc1--topic1' partition 1. Step TInitInternalFieldsStep
2025-10-26T18:07:22.681888Z node 11 :PERSQUEUE DEBUG: Initializing topic 'rt3.dc1--topic1' partition 0. Step TInitConfigStep
2025-10-26T18:07:22.681907Z node 11 :PERSQUEUE INFO: bootstrapping 1 [11:7565593665476629358:8233]
2025-10-26T18:07:22.681983Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-10-26T18:07:22.682440Z node 11 :PERSQUEUE DEBUG: Initializing topic 'rt3.dc1--topic1' partition 0. Step TInitInternalFieldsStep
2025-10-26T18:07:22.682757Z node 11 :PERSQUEUE INFO: bootstrapping 0 [11:7565593665476629360:4297]
2025-10-26T18:07:22.690067Z node 11 :PERSQUEUE DEBUG: Initializing topic 'rt3.dc1--topic1' partition 0. Completed.
2025-10-26T18:07:22.690114Z node 11 :PERSQUEUE INFO: init complete for topic 'rt3.dc1--topic1' partition 0 generation 1 [11:7565593665476629360:4297]
2025-10-26T18:07:22.690143Z node 11 :PERSQUEUE DEBUG: SYNC INIT topic rt3.dc1--topic1 partitition 0 so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-10-26T18:07:22.691699Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-10-26T18:07:22.691882Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 0 user user readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-10-26T18:07:22.692411Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvProposePartitionConfigResult Step 1761502042699, TxId 281474976710679, Partition 0
2025-10-26T18:07:22.692433Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] Handle TEvProposePartitionConfigResult
2025-10-26T18:07:22.692452Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] Partition responses 1/2
2025-10-26T18:07:22.692476Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATING
2025-10-26T18:07:22.692497Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State CALCULATING
2025-10-26T18:07:22.692521Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 State CALCULATING FrontTxId 281474976710679
2025-10-26T18:07:22.692542Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Received 1, Expected 2
2025-10-26T18:07:22.692563Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 status has not changed
2025-10-26T18:07:22.695276Z node 11 :PERSQUEUE DEBUG: Initializing topic 'rt3.dc1--topic1' partition 1. Completed.
2025-10-26T18:07:22.695317Z node 11 :PERSQUEUE INFO: init complete for topic 'rt3.dc1--topic1' partition 1 generation 1 [11:7565593665476629358:8233]
2025-10-26T18:07:22.695347Z node 11 :PERSQUEUE DEBUG: SYNC INIT topic rt3.dc1--topic1 partitition 1 so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-10-26T18:07:22.696602Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 1, State: StateIdle] Process pending events. Count 1
2025-10-26T18:07:22.696812Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 user user readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-10-26T18:07:22.697194Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvProposePartitionConfigResult Step 1761502042699, TxId 281474976710679, Partition 1
2025-10-26T18:07:22.697218Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] Handle TEvProposePartitionConfigResult
2025-10-26T18:07:22.697238Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] Partition responses 2/2
2025-10-26T18:07:22.697262Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATING
2025-10-26T18:07:22.697285Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State CALCULATING
2025-10-26T18:07:22.697313Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 State CALCULATING FrontTxId 281474976710679
2025-10-26T18:07:22.697333Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Received 2, Expected 2
2025-10-26T18:07:22.697362Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState CALCULATED
2025-10-26T18:07:22.697398Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 moved from CALCULATING to CALCULATED
2025-10-26T18:07:22.697428Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] write key for TxId 281474976710679
2025-10-26T18:07:22.698475Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] save tx TxId: 281474976710679 State: CALCULATED MinStep: 1761502042643 MaxStep: 18446744073709551615 Step: 1761502042699 Predicate: true Kind: KIND_CONFIG TabletConfig { PartitionConfig { LifetimeSeconds: 86400 LowWatermark: 8388608 SourceIdLifetimeSeconds: 86400 WriteSpeedInBytesPerSecond: 20000000 BurstSize: 20000000 TotalPartitions: 2 SourceIdMaxCounts: 6000000 } PartitionIds: 1 PartitionIds: 0 TopicName: "rt3.dc1--topic1" Version: 0 LocalDC: true ReadRules: "user" ReadFromTimestampsMs: 0 ConsumerFormatVersions: 0 ConsumerCodecs { } Codecs { Ids: 0 Ids: 1 Ids: 2 Codecs: "raw" Codecs: "gzip" Codecs: "lzop" } ReadRuleVersions: 0 TopicPath: "/Root/PQ/rt3.dc1--topic1" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 1 Status: Active CreateVersion: 1 TabletId: 0 } Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 Consumers { Name: "user" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } Version: 0 Generation: 0 Important: false } } BootstrapConfig { } SourceActor { RawX1: 7565593613937020559 RawX2: 47244652602 }
2025-10-26T18:07:22.698649Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-10-26T18:07:22.707266Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-10-26T18:07:22.707317Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATED
2025-10-26T18:07:22.707362Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State CALCULATED
2025-10-26T18:07:22.707397Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 State CALCULATED FrontTxId 281474976710679
2025-10-26T18:07:22.707421Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState WAIT_RS
2025-10-26T18:07:22.707466Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 moved from CALCULATED to WAIT_RS
2025-10-26T18:07:22.707507Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-10-26T18:07:22.707532Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] HaveParticipantsDecision 1
2025-10-26T18:07:22.707570Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState EXECUTING
2025-10-26T18:07:22.707598Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 moved from WAIT_RS to EXECUTING
2025-10-26T18:07:22.707616Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Received 0, Expected 2
2025-10-26T18:07:22.707671Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1761502042699, TxId 281474976710679
2025-10-26T18:07:22.708183Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 1, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1761502042699, TxId 281474976710679
2025-10-26T18:07:22.708475Z node 11 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-10-26T18:07:22.708592Z node 11 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-10-26T18:07:22.712534Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-10-26T18:07:22.712790Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 1, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-10-26T18:07:22.712911Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvTxCommitDone Step 1761502042699, TxId 281474976710679, Partition 0
2025-10-26T18:07:22.712946Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTING
2025-10-26T18:07:22.712973Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State EXECUTING
2025-10-26T18:07:22.712996Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 State EXECUTING FrontTxId 281474976710679
2025-10-26T18:07:22.713013Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Received 1, Expected 2
2025-10-26T18:07:22.713031Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 status has not changed
2025-10-26T18:07:22.713075Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvTxCommitDone Step 1761502042699, TxId 281474976710679, Partition 1
2025-10-26T18:07:22.713089Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTING
2025-10-26T18:07:22.713101Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State EXECUTING
2025-10-26T18:07:22.713114Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 State EXECUTING FrontTxId 281474976710679
2025-10-26T18:07:22.713125Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Received 2, Expected 2
2025-10-26T18:07:22.713158Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId: 281474976710679 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-10-26T18:07:22.713195Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] complete TxId 281474976710679
2025-10-26T18:07:22.713555Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Apply new config PartitionConfig { LifetimeSeconds: 86400 LowWatermark: 8388608 SourceIdLifetimeSeconds: 86400 WriteSpeedInBytesPerSecond: 20000000 BurstSize: 20000000 TotalPartitions: 2 SourceIdMaxCounts: 6000000 } PartitionIds: 1 PartitionIds: 0 TopicName: "rt3.dc1--topic1" Version: 0 LocalDC: true ReadRules: "user" ReadFromTimestampsMs: 0 ConsumerFormatVersions: 0 ConsumerCodecs { } Codecs { Ids: 0 Ids: 1 Ids: 2 Codecs: "raw" Codecs: "gzip" Codecs: "lzop" } ReadRuleVersions: 0 TopicPath: "/Root/PQ/rt3.dc1--topic1" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 1 Status: Active CreateVersion: 1 TabletId: 0 } Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 Consumers { Name: "user" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } Version: 0 Generation: 0 Important: false }
2025-10-26T18:07:22.713655Z node 11 :PERSQUEUE NOTICE: Tablet 72075186224037892 disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-10-26T18:07:22.713760Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] delete partitions for TxId 281474976710679
2025-10-26T18:07:22.713784Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState EXECUTED
2025-10-26T18:07:22.713812Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 moved from EXECUTING to EXECUTED
2025-10-26T18:07:22.713841Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] write key for TxId 281474976710679
2025-10-26T18:07:22.714225Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] save tx TxId: 281474976710679 State: EXECUTED MinStep: 1761502042643 MaxStep: 18446744073709551615 Step: 1761502042699 Predicate: true Kind: KIND_CONFIG TabletConfig { PartitionConfig { LifetimeSeconds: 86400 LowWatermark: 8388608 SourceIdLifetimeSeconds: 86400 WriteSpeedInBytesPerSecond: 20000000 BurstSize: 20000000 TotalPartitions: 2 SourceIdMaxCounts: 6000000 } PartitionIds: 1 PartitionIds: 0 TopicName: "rt3.dc1--topic1" Version: 0 LocalDC: true ReadRules: "user" ReadFromTimestampsMs: 0 ConsumerFormatVersions: 0 ConsumerCodecs { } Codecs { Ids: 0 Ids: 1 Ids: 2 Codecs: "raw" Codecs: "gzip" Codecs: "lzop" } ReadRuleVersions: 0 TopicPath: "/Root/PQ/rt3.dc1--topic1" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 1 Status: Active CreateVersion: 1 TabletId: 0 } Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 Consumers { Name: "user" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } Version: 0 Generation: 0 Important: false } } BootstrapConfig { } SourceActor { RawX1: 7565593613937020559 RawX2: 47244652602 }
2025-10-26T18:07:22.714463Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-10-26T18:07:22.721342Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-10-26T18:07:22.721384Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTED
2025-10-26T18:07:22.721406Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State EXECUTED
2025-10-26T18:07:22.721432Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 State EXECUTED FrontTxId 281474976710679
2025-10-26T18:07:22.721455Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TPersQueue::SendEvReadSetAckToSenders
2025-10-26T18:07:22.721481Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState WAIT_RS_ACKS
2025-10-26T18:07:22.721503Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679 moved from EXECUTED to WAIT_RS_ACKS
2025-10-26T18:07:22.721531Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] PredicateAcks: 0/0
2025-10-26T18:07:22.721543Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-10-26T18:07:22.721561Z node 11 :PERSQUEUE DEBUG: [TxId: 281474976710679] PredicateAcks: 0/0
2025-10-26T18:07:22.721580Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] add an TxId 281474976710679 to the list for deletion
2025-10-26T18:07:22.721605Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, NewState DELETING
2025-10-26T18:07:22.721635Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] delete key for TxId 281474976710679
2025-10-26T18:07:22.721748Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-10-26T18:07:22.722952Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-10-26T18:07:22.722984Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Try execute txs with state DELETING
2025-10-26T18:07:22.723005Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] TxId 281474976710679, State DELETING
2025-10-26T18:07:22.723028Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892] delete TxId 281474976710679
2025-10-26T18:07:22.887723Z node 11 :KQP_EXECUTER ERROR: TxId: 281474976710680. Ctx: { TraceId: 01k8gv86j31nfnccgddbqbnhnp, Database: , DatabaseId: /Root, SessionId: ydb://session/3?node_id=11&id=NTYxZTQ0ZmMtNzNjMDhmMWYtOTJiMTc0ODktZjMyZjdhMWI=, CurrentExecutionId: , CustomerSuppliedId: , PoolId: }. Database not set, use /Root
===Query complete
TClient::Ls request: /Root/PQ/rt3.dc1--topic1
TClient::Ls response: Status: 1
StatusCode: SUCCESS
SchemeStatus: 0
PathDescription {
  Self {
    Name: "rt3.dc1--topic1"
    PathId: 9
    SchemeshardId: 72057594046644480
    PathType: EPathTypePersQueueGroup
    CreateFinished: true
    CreateTxId: 281474976710679
    CreateStep: 1761502042699
    ParentPathId: 2
    PathState: EPathStateNoChanges
    Owner: "root@builtin"
    ACL: ""
    EffectiveACL: ""
    PathVersion: 2
    PathSubType: EPathSubTypeEmpty
    Version {
      GeneralVersion: 2
      ACLVersion: 0
      EffectiveACLVersion: 0
      UserAttrsVersion: 1
      ChildrenVersion: 0
      PQVersion: 1
    }
    BalancerTabletID: 72075186224037893
  }
  PersQueueGroup {
    Name: "rt3.dc1--topic1"
    PathId: 9
    TotalGroupCount: 2
    PartitionPerTablet: 5
    PQTabletConfig {
      PartitionConfig {
        LifetimeSeconds: 86400
        LowWatermark: 8388608
        SourceIdLifetimeSeconds: 86400
        WriteSpeedInBytesPerSecond: 20000000
        BurstSize: 20000000
        SourceIdMaxC...
(TRUNCATED)
GetTopicVersionFromPath:  record Status: 1
StatusCode: SUCCESS
SchemeStatus: 0
PathDescription {
  Self {
    Name: "rt3.dc1--topic1"
    PathId: 9
    SchemeshardId: 72057594046644480
    PathType: EPathTypePersQueueGroup
    CreateFinished: true
    CreateTxId: 281474976710679
    CreateStep: 1761502042699
    ParentPathId: 2
    PathState: EPathStateNoChanges
    Owner: "root@builtin"
    ACL: ""
    EffectiveACL: ""
    PathVersion: 2
    PathSubType: EPathSubTypeEmpty
    Version {
      GeneralVersion: 2
      ACLVersion: 0
      EffectiveACLVersion: 0
      UserAttrsVersion: 1
      ChildrenVersion: 0
      PQVersion: 1
    }
    BalancerTabletID: 72075186224037893
  }
  PersQueueGroup {
    Name: "rt3.dc1--topic1"
    PathId: 9
    TotalGroupCount: 2
    PartitionPerTablet: 5
    PQTabletConfig {
      PartitionConfig {
        LifetimeSeconds: 86400
        LowWatermark: 8388608
        SourceIdLifetimeSeconds: 86400
        WriteSpeedInBytesPerSecond: 20000000
        BurstSize: 20000000
        SourceIdMaxCounts: 6000000
      }
      LocalDC: true
      ReadRules: "user"
      ReadFromTimestampsMs: 0
      ConsumerFormatVersions: 0
      ConsumerCodecs {
      }
      Codecs {
        Ids: 0
        Ids: 1
        Ids: 2
        Codecs: "raw"
        Codecs: "gzip"
        Codecs: "lzop"
      }
      ReadRuleVersions: 0
      YdbDatabasePath: "/Root"
    }
    Partitions {
      PartitionId: 0
      TabletId: 72075186224037892
      Status: Active
    }
    Partitions {
      PartitionId: 1
      TabletId: 72075186224037892
      Status: Active
    }
    AlterVersion: 1
    BalancerTabletID: 72075186224037893
    NextPartitionId: 2
  }
  DomainDescription {
    SchemeShardId_Depricated: 72057594046644480
    PathId_Depricated: 1
    ProcessingParams {
      Version: 1
      PlanResolution: 7
      Coordinators: 72057594046316545
      TimeCastBucketsPerMediator: 2
      Mediators: 72057594046382081
    }
    DomainKey {
      SchemeShard: 72057594046644480
      PathId: 1
    }
    PathsInside: 8
    PathsLimit: 10000
    ShardsInside: 6
    ShardsLimit: 200000
    ResourcesDomainKey {
      SchemeShard: 72057594046644480
      PathId: 1
    }
    DiskSpaceUsage {
      Tables {
        TotalSize: 0
        DataSize: 0
        IndexSize: 0
      }
      Topics {
        ReserveSize: 0
        AccountSize: 0
        DataSize: 0
        UsedReserveSize: 0
      }
    }
    PQPartitionsInside: 2
    PQPartitionsLimit: 1000000
  }
}
Path: "/Root/PQ/rt3.dc1--topic1"
 name rt3.dc1--topic1 version1
CallPersQueueGRPC request to localhost:15705
MetaRequest {
  CmdGetTopicMetadata {
    Topic: "rt3.dc1--topic1"
  }
}
2025-10-26T18:07:22.929041Z node 11 :PERSQUEUE INFO: proxy answer <none>
CallPersQueueGRPC response:
Status: 128
ErrorReason: "the following topics are not created: rt3.dc1--topic1, Marker# PQ95"
ErrorCode: UNKNOWN_TOPIC
CallPersQueueGRPC request to localhost:15705
MetaRequest {
  CmdGetTopicMetadata {
    Topic: "rt3.dc1--topic1"
  }
}
2025-10-26T18:07:23.432847Z node 11 :PERSQUEUE INFO: proxy answer <none>
CallPersQueueGRPC response:
Status: 128
ErrorReason: "the following topics are not created: rt3.dc1--topic1, Marker# PQ95"
ErrorCode: UNKNOWN_TOPIC
CallPersQueueGRPC request to localhost:15705
MetaRequest {
  CmdGetTopicMetadata {
    Topic: "rt3.dc1--topic1"
  }
}
2025-10-26T18:07:23.943422Z node 11 :PERSQUEUE INFO: proxy answer <none>
CallPersQueueGRPC response:
Status: 1
ErrorCode: OK
MetaResponse {
  CmdGetTopicMetadataResult {
    TopicInfo {
      Topic: "rt3.dc1--topic1"
      NumPartitions: 2
      Config {
        PartitionConfig {
          LifetimeSeconds: 86400
          LowWatermark: 8388608
          SourceIdLifetimeSeconds: 86400
          WriteSpeedInBytesPerSecond: 20000000
          BurstSize: 20000000
          SourceIdMaxCounts: 6000000
        }
        Version: 1
        LocalDC: true
        ReadRules: "user"
        ReadFromTimestampsMs: 0
        ConsumerFormatVersions: 0
        ConsumerCodecs {
        }
        Codecs {
          Ids: 0
          Ids: 1
          Ids: 2
          Codecs: "raw"
          Codecs: "gzip"
          Codecs: "lzop"
        }
        ReadRuleVersions: 0
        TopicPath: "/Root/PQ/rt3.dc1--topic1"
        YdbDatabasePath: "/Root"
        Consumers {
          Name: "user"
          ReadFromTimestampsMs: 0
          FormatVersion: 0
          Codec {
          }
          Version: 0
        ...
(TRUNCATED)
=== Topic created, have version: 1
2025-10-26T18:07:23.953865Z node 11 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-10-26T18:07:23.953915Z node 11 :PQ_WRITE_PROXY DEBUG: new session created cookie 1
2025-10-26T18:07:23.954930Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic1" message_group_id: "12345678" }
2025-10-26T18:07:23.955084Z node 11 :PQ_WRITE_PROXY INFO: session request cookie: 1 topic: "topic1" message_group_id: "12345678" from ipv6:[::1]:51370
2025-10-26T18:07:23.955104Z node 11 :PQ_WRITE_PROXY INFO: write session:  cookie=1 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:51370 proto=v1  topic=topic1 durationSec=0
2025-10-26T18:07:23.955118Z node 11 :PQ_WRITE_PROXY INFO: init check schema
2025-10-26T18:07:23.958879Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId:  describe result for acl check
2025-10-26T18:07:23.959016Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint32; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `/Root/PQ/SourceIdMeta2` WHERE Hash == $Hash AND Topic == $Topic AND SourceId == $SourceId;
2025-10-26T18:07:23.959028Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;DECLARE $SeqNo AS Uint64;
UPSERT INTO `/Root/PQ/SourceIdMeta2` (Hash, Topic, SourceId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-10-26T18:07:23.959042Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `/Root/PQ/SourceIdMeta2` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND SourceId = $SourceId AND Partition = $Partition;
2025-10-26T18:07:23.959062Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593669771596819:4294] (SourceId=12345678, PreferedPartition=(NULL)) StartKqpSession
2025-10-26T18:07:23.962539Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593669771596819:4294] (SourceId=12345678, PreferedPartition=(NULL)) Select from the table
2025-10-26T18:07:24.160970Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593669771596819:4294] (SourceId=12345678, PreferedPartition=(NULL)) RequestPQRB
2025-10-26T18:07:24.161297Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic rt3.dc1--topic1 pipe [11:7565593674066564169:4294] connected; active server actors: 1
2025-10-26T18:07:24.161520Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593669771596819:4294] (SourceId=12345678, PreferedPartition=(NULL)) Received partition 0 from PQRB for SourceId=12345678
2025-10-26T18:07:24.161546Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593669771596819:4294] (SourceId=12345678, PreferedPartition=(NULL)) Update the table
2025-10-26T18:07:24.162202Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic rt3.dc1--topic1 pipe [11:7565593674066564169:4294] disconnected; active server actors: 1
2025-10-26T18:07:24.162228Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic rt3.dc1--topic1 pipe [11:7565593674066564169:4294] disconnected no session
2025-10-26T18:07:24.322783Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593669771596819:4294] (SourceId=12345678, PreferedPartition=(NULL)) HandleUpdate PartitionPersisted=0 Status=SUCCESS
2025-10-26T18:07:24.322851Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593669771596819:4294] (SourceId=12345678, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=(NULL)
2025-10-26T18:07:24.322878Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593669771596819:4294] (SourceId=12345678, PreferedPartition=(NULL)) Start idle
2025-10-26T18:07:24.322919Z node 11 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 1 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-10-26T18:07:24.324650Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 11, Generation: 1
2025-10-26T18:07:24.324715Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server connected, pipe [11:7565593674066564189:4294], now have 1 active actors on pipe
2025-10-26T18:07:24.324881Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.324925Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.325017Z node 11 :PERSQUEUE INFO: new Cookie 12345678|4a832f59-41bb056a-d8502915-12ddc9d5_0 generated for partition 0 topic 'rt3.dc1--topic1' owner 12345678
2025-10-26T18:07:24.325111Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyOwnerOk. Partition: 0
2025-10-26T18:07:24.325186Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.325426Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.325448Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.325526Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.325663Z node 11 :PQ_WRITE_PROXY INFO: session inited cookie: 1 partition: 0 MaxSeqNo: 0 sessionId: 12345678|4a832f59-41bb056a-d8502915-12ddc9d5_0
2025-10-26T18:07:24.330681Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId: 12345678|4a832f59-41bb056a-d8502915-12ddc9d5_0 grpc read done: success: 0 data: 
2025-10-26T18:07:24.330714Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: 12345678|4a832f59-41bb056a-d8502915-12ddc9d5_0 grpc read failed
2025-10-26T18:07:24.330891Z node 11 :PQ_WRITE_PROXY INFO: session v1 closed cookie: 1 sessionId: 12345678|4a832f59-41bb056a-d8502915-12ddc9d5_0
2025-10-26T18:07:24.330926Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: 12345678|4a832f59-41bb056a-d8502915-12ddc9d5_0 is DEAD
2025-10-26T18:07:24.331328Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
Finish: 0 
2025-10-26T18:07:24.333803Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server disconnected, pipe [11:7565593674066564189:4294] destroyed
2025-10-26T18:07:24.333870Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-10-26T18:07:24.335593Z node 11 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-10-26T18:07:24.335632Z node 11 :PQ_WRITE_PROXY DEBUG: new session created cookie 2
2025-10-26T18:07:24.336030Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic1" message_group_id: "12345678" }
2025-10-26T18:07:24.336196Z node 11 :PQ_WRITE_PROXY INFO: session request cookie: 2 topic: "topic1" message_group_id: "12345678" from ipv6:[::1]:51370
2025-10-26T18:07:24.336216Z node 11 :PQ_WRITE_PROXY INFO: write session:  cookie=2 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:51370 proto=v1  topic=topic1 durationSec=0
2025-10-26T18:07:24.336228Z node 11 :PQ_WRITE_PROXY INFO: init check schema
2025-10-26T18:07:24.338443Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId:  describe result for acl check
2025-10-26T18:07:24.338602Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint32; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `/Root/PQ/SourceIdMeta2` WHERE Hash == $Hash AND Topic == $Topic AND SourceId == $SourceId;
2025-10-26T18:07:24.338615Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;DECLARE $SeqNo AS Uint64;
UPSERT INTO `/Root/PQ/SourceIdMeta2` (Hash, Topic, SourceId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-10-26T18:07:24.338631Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `/Root/PQ/SourceIdMeta2` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND SourceId = $SourceId AND Partition = $Partition;
2025-10-26T18:07:24.338653Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564195:4300] (SourceId=12345678, PreferedPartition=(NULL)) StartKqpSession
2025-10-26T18:07:24.342296Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564195:4300] (SourceId=12345678, PreferedPartition=(NULL)) Select from the table
2025-10-26T18:07:24.350174Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564195:4300] (SourceId=12345678, PreferedPartition=(NULL)) Update the table
2025-10-26T18:07:24.359898Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564195:4300] (SourceId=12345678, PreferedPartition=(NULL)) HandleUpdate PartitionPersisted=0 Status=SUCCESS
2025-10-26T18:07:24.359941Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564195:4300] (SourceId=12345678, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-10-26T18:07:24.359961Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564195:4300] (SourceId=12345678, PreferedPartition=(NULL)) Start idle
2025-10-26T18:07:24.359989Z node 11 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 2 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-10-26T18:07:24.360701Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server connected, pipe [11:7565593674066564219:4300], now have 1 active actors on pipe
2025-10-26T18:07:24.360759Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 11, Generation: 1
2025-10-26T18:07:24.360922Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.360962Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.361048Z node 11 :PERSQUEUE INFO: new Cookie 12345678|24d0a1ff-614025bd-68b533e7-af93e854_0 generated for partition 0 topic 'rt3.dc1--topic1' owner 12345678
2025-10-26T18:07:24.361131Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyOwnerOk. Partition: 0
2025-10-26T18:07:24.361200Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.361377Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.361399Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.361485Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.361653Z node 11 :PQ_WRITE_PROXY INFO: session inited cookie: 2 partition: 0 MaxSeqNo: 0 sessionId: 12345678|24d0a1ff-614025bd-68b533e7-af93e854_0
2025-10-26T18:07:24.369381Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId: 12345678|24d0a1ff-614025bd-68b533e7-af93e854_0 grpc read done: success: 0 data: 
2025-10-26T18:07:24.369413Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: 12345678|24d0a1ff-614025bd-68b533e7-af93e854_0 grpc read failed
2025-10-26T18:07:24.369591Z node 11 :PQ_WRITE_PROXY INFO: session v1 closed cookie: 2 sessionId: 12345678|24d0a1ff-614025bd-68b533e7-af93e854_0
2025-10-26T18:07:24.369610Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: 12345678|24d0a1ff-614025bd-68b533e7-af93e854_0 is DEAD
2025-10-26T18:07:24.370059Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-10-26T18:07:24.370483Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server disconnected, pipe [11:7565593674066564219:4300] destroyed
2025-10-26T18:07:24.370543Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
Finish: 0 
2025-10-26T18:07:24.375189Z node 11 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-10-26T18:07:24.375226Z node 11 :PQ_WRITE_PROXY DEBUG: new session created cookie 3
2025-10-26T18:07:24.378345Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic1" message_group_id: "source1" session_meta { key: "key" value: "value" } }
2025-10-26T18:07:24.378633Z node 11 :PQ_WRITE_PROXY INFO: session request cookie: 3 topic: "topic1" message_group_id: "source1" session_meta { key: "key" value: "value" } from ipv6:[::1]:51370
2025-10-26T18:07:24.378673Z node 11 :PQ_WRITE_PROXY INFO: write session:  cookie=3 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:51370 proto=v1  topic=topic1 durationSec=0
2025-10-26T18:07:24.379157Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId:  is DEAD
16 unauthenticated, Unauthenticated access is forbidden, please provide credentials
{  }
2025-10-26T18:07:24.388486Z node 11 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-10-26T18:07:24.388539Z node 11 :PQ_WRITE_PROXY DEBUG: new session created cookie 4
2025-10-26T18:07:24.389407Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic1" message_group_id: "source1" session_meta { key: "key" value: "value" } }
2025-10-26T18:07:24.389647Z node 11 :PQ_WRITE_PROXY INFO: session request cookie: 4 topic: "topic1" message_group_id: "source1" session_meta { key: "key" value: "value" } from ipv6:[::1]:51370
2025-10-26T18:07:24.389673Z node 11 :PQ_WRITE_PROXY INFO: write session:  cookie=4 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:51370 proto=v1  topic=topic1 durationSec=0
2025-10-26T18:07:24.389699Z node 11 :PQ_WRITE_PROXY INFO: init check schema
2025-10-26T18:07:24.392145Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId:  describe result for acl check
2025-10-26T18:07:24.392312Z node 11 :PQ_WRITE_PROXY INFO: session v1 error cookie: 4 reason: access to topic 'Topic topic1 in dc dc1' denied for 'topic1@builtin' due to 'no WriteTopic rights', Marker# PQ1125 sessionId: 
2025-10-26T18:07:24.392688Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId:  is DEAD
{ status: UNAUTHORIZED issues { message: "access to topic \'Topic topic1 in dc dc1\' denied for \'topic1@builtin\' due to \'no WriteTopic rights\', Marker# PQ1125" issue_code: 500018 severity: 1 } }
BEFORE MODIFY PERMISSIONS
2025-10-26T18:07:24.419362Z node 11 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpModifyACL, opId: 281474976710689:0, at schemeshard:  72057594046644480
2025-10-26T18:07:24.425255Z node 11 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-10-26T18:07:24.425286Z node 11 :PQ_WRITE_PROXY DEBUG: new session created cookie 5
2025-10-26T18:07:24.425879Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic1" message_group_id: "source1" session_meta { key: "key" value: "value" } }
2025-10-26T18:07:24.426078Z node 11 :PQ_WRITE_PROXY INFO: session request cookie: 5 topic: "topic1" message_group_id: "source1" session_meta { key: "key" value: "value" } from ipv6:[::1]:51370
2025-10-26T18:07:24.426096Z node 11 :PQ_WRITE_PROXY INFO: write session:  cookie=5 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:51370 proto=v1  topic=topic1 durationSec=0
2025-10-26T18:07:24.426109Z node 11 :PQ_WRITE_PROXY INFO: init check schema
2025-10-26T18:07:24.427955Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId:  describe result for acl check
2025-10-26T18:07:24.428169Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint32; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `/Root/PQ/SourceIdMeta2` WHERE Hash == $Hash AND Topic == $Topic AND SourceId == $SourceId;
2025-10-26T18:07:24.428183Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;DECLARE $SeqNo AS Uint64;
UPSERT INTO `/Root/PQ/SourceIdMeta2` (Hash, Topic, SourceId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-10-26T18:07:24.428198Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `/Root/PQ/SourceIdMeta2` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND SourceId = $SourceId AND Partition = $Partition;
2025-10-26T18:07:24.428221Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564242:4267] (SourceId=source1, PreferedPartition=(NULL)) StartKqpSession
2025-10-26T18:07:24.431593Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564242:4267] (SourceId=source1, PreferedPartition=(NULL)) Select from the table
2025-10-26T18:07:24.442154Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564242:4267] (SourceId=source1, PreferedPartition=(NULL)) RequestPQRB
2025-10-26T18:07:24.442592Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic rt3.dc1--topic1 pipe [11:7565593674066564258:4267] connected; active server actors: 1
2025-10-26T18:07:24.442745Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564242:4267] (SourceId=source1, PreferedPartition=(NULL)) Received partition 1 from PQRB for SourceId=source1
2025-10-26T18:07:24.442772Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564242:4267] (SourceId=source1, PreferedPartition=(NULL)) Update the table
2025-10-26T18:07:24.443325Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic rt3.dc1--topic1 pipe [11:7565593674066564258:4267] disconnected; active server actors: 1
2025-10-26T18:07:24.443355Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic rt3.dc1--topic1 pipe [11:7565593674066564258:4267] disconnected no session
2025-10-26T18:07:24.449769Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564242:4267] (SourceId=source1, PreferedPartition=(NULL)) HandleUpdate PartitionPersisted=0 Status=SUCCESS
2025-10-26T18:07:24.449824Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564242:4267] (SourceId=source1, PreferedPartition=(NULL)) ReplyResult: Partition=1, SeqNo=(NULL)
2025-10-26T18:07:24.449849Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564242:4267] (SourceId=source1, PreferedPartition=(NULL)) Start idle
2025-10-26T18:07:24.449887Z node 11 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 5 sessionId:  partition: 1 expectedGeneration: (NULL)
2025-10-26T18:07:24.450729Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 11, Generation: 1
2025-10-26T18:07:24.450753Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server connected, pipe [11:7565593674066564268:4267], now have 1 active actors on pipe
2025-10-26T18:07:24.450905Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.450932Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.451020Z node 11 :PERSQUEUE INFO: new Cookie source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 generated for partition 1 topic 'rt3.dc1--topic1' owner source1
2025-10-26T18:07:24.451099Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyOwnerOk. Partition: 1
2025-10-26T18:07:24.451158Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.451338Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.451356Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.451430Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.451558Z node 11 :PQ_WRITE_PROXY INFO: session inited cookie: 5 partition: 1 MaxSeqNo: 0 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0
update user token request: { update_token_request { token: "topic1@builtin" } }
2025-10-26T18:07:24.452838Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read done: success: 1 data:  update_token_request [content omitted]
request: { write_request { sequence_numbers: 2 created_at_ms: 1761502044453 sent_at_ms: 1761502044453 message_sizes: 16 blocks_offsets: 0 blocks_part_numbers: 0 blocks_message_counts: 1 blocks_uncompressed_sizes: 16 blocks_headers: "\000" blocks_data: "valuevaluevalue1" } }
2025-10-26T18:07:24.453780Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-10-26T18:07:24.454065Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-10-26T18:07:24.454376Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.454400Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.454512Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 0  requestId: <none> cookie: 1
2025-10-26T18:07:24.454569Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-10-26T18:07:24.454852Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.454870Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.455193Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message topic: rt3.dc1--topic1 partition: 1 SourceId: '\0source1' SeqNo: 2 partNo : 0 messageNo: 1 size 104 offset: -1
2025-10-26T18:07:24.455349Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 part blob processing sourceId '\0source1' seqNo 2 partNo 0
2025-10-26T18:07:24.540250Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 part blob complete sourceId '\0source1' seqNo 2 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 179 count 1 nextOffset 1 batches 1
2025-10-26T18:07:24.540888Z node 11 :PERSQUEUE DEBUG: Add new write blob: topic 'rt3.dc1--topic1' partition 1 compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 d0000000001_00000000000000000000_00000_0000000001_00000| size 167 WTime 1761502044540
2025-10-26T18:07:24.541123Z node 11 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-10-26T18:07:24.543644Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 1, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 112 WriteNewSizeFromSupportivePartitions# 0
2025-10-26T18:07:24.543687Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyWrite. Partition: 1
2025-10-26T18:07:24.543725Z node 11 :PERSQUEUE DEBUG: Answering for message sourceid: '\0source1', Topic: 'rt3.dc1--topic1', Partition: 1, SeqNo: 2, partNo: 0, Offset: 0 is stored on disk
2025-10-26T18:07:24.543879Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 user user readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-10-26T18:07:24.543898Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 user user send read request for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 1 rrg 0
2025-10-26T18:07:24.543991Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 1  requestId: <none> cookie: 1
2025-10-26T18:07:24.544120Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-10-26T18:07:24.544543Z node 11 :PERSQUEUE DEBUG: read cookie 0 Topic 'rt3.dc1--topic1' partition 1 user user offset 0 count 1 size 1024000 endOffset 1 max time lag 0ms effective offset 0
2025-10-26T18:07:24.544561Z node 11 :PERSQUEUE DEBUG: read cookie 0 added 0 blobs, size 0 count 0 last offset 0
2025-10-26T18:07:24.544589Z node 11 :PERSQUEUE DEBUG: Reading cookie 0. All data is from uncompacted head.
2025-10-26T18:07:24.544607Z node 11 :PERSQUEUE DEBUG: FormAnswer 0
2025-10-26T18:07:24.544706Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 user user readTimeStamp done, result 1761502044454 queuesize 0 startOffset 0
update user token request: { update_token_request { token: "topic1@builtin" } }
2025-10-26T18:07:24.546062Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read done: success: 1 data:  update_token_request [content omitted]
request: { write_request { sequence_numbers: 3 created_at_ms: 1761502044546 sent_at_ms: 1761502044546 message_sizes: 16 blocks_offsets: 0 blocks_part_numbers: 0 blocks_message_counts: 1 blocks_uncompressed_sizes: 16 blocks_headers: "\000" blocks_data: "valuevaluevalue1" } }
2025-10-26T18:07:24.546991Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-10-26T18:07:24.547179Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-10-26T18:07:24.547488Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.547520Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.547586Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 2  requestId: <none> cookie: 2
2025-10-26T18:07:24.547628Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-10-26T18:07:24.547752Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.547765Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.547811Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message topic: rt3.dc1--topic1 partition: 1 SourceId: '\0source1' SeqNo: 3 partNo : 0 messageNo: 3 size 104 offset: -1
2025-10-26T18:07:24.547923Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 part blob processing sourceId '\0source1' seqNo 3 partNo 0
2025-10-26T18:07:24.549312Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 part blob complete sourceId '\0source1' seqNo 3 partNo 0 FormedBlobsCount 0 NewHead: Offset 1 PartNo 0 PackedSize 179 count 1 nextOffset 2 batches 1
2025-10-26T18:07:24.549810Z node 11 :PERSQUEUE DEBUG: Add new write blob: topic 'rt3.dc1--topic1' partition 1 compactOffset 1,1 HeadOffset 0 endOffset 1 curOffset 2 d0000000001_00000000000000000001_00000_0000000001_00000| size 167 WTime 1761502044549
2025-10-26T18:07:24.550006Z node 11 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-10-26T18:07:24.551065Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 1, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 112 WriteNewSizeFromSupportivePartitions# 0
2025-10-26T18:07:24.551093Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyWrite. Partition: 1
2025-10-26T18:07:24.551135Z node 11 :PERSQUEUE DEBUG: Answering for message sourceid: '\0source1', Topic: 'rt3.dc1--topic1', Partition: 1, SeqNo: 3, partNo: 0, Offset: 1 is stored on disk
2025-10-26T18:07:24.551167Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 3  requestId: <none> cookie: 2
2025-10-26T18:07:24.551233Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::TEvPersQueue::TEvResponse
update user token request: { update_token_request { token: "topic1@builtin" } }
2025-10-26T18:07:24.552359Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read done: success: 1 data:  update_token_request [content omitted]
request: { write_request { sequence_numbers: 4 created_at_ms: 1761502044552 sent_at_ms: 1761502044552 message_sizes: 16 blocks_offsets: 0 blocks_part_numbers: 0 blocks_message_counts: 1 blocks_uncompressed_sizes: 16 blocks_headers: "\000" blocks_data: "valuevaluevalue1" } }
2025-10-26T18:07:24.553317Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-10-26T18:07:24.553559Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-10-26T18:07:24.553881Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.553911Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.554028Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 4  requestId: <none> cookie: 3
2025-10-26T18:07:24.554082Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-10-26T18:07:24.554235Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.554252Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.554301Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message topic: rt3.dc1--topic1 partition: 1 SourceId: '\0source1' SeqNo: 4 partNo : 0 messageNo: 5 size 104 offset: -1
2025-10-26T18:07:24.554454Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 part blob processing sourceId '\0source1' seqNo 4 partNo 0
2025-10-26T18:07:24.555950Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 part blob complete sourceId '\0source1' seqNo 4 partNo 0 FormedBlobsCount 0 NewHead: Offset 2 PartNo 0 PackedSize 179 count 1 nextOffset 3 batches 1
2025-10-26T18:07:24.556532Z node 11 :PERSQUEUE DEBUG: Add new write blob: topic 'rt3.dc1--topic1' partition 1 compactOffset 2,1 HeadOffset 0 endOffset 2 curOffset 3 d0000000001_00000000000000000002_00000_0000000001_00000| size 167 WTime 1761502044556
2025-10-26T18:07:24.556765Z node 11 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-10-26T18:07:24.557891Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 1, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 112 WriteNewSizeFromSupportivePartitions# 0
2025-10-26T18:07:24.557927Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyWrite. Partition: 1
2025-10-26T18:07:24.557980Z node 11 :PERSQUEUE DEBUG: Answering for message sourceid: '\0source1', Topic: 'rt3.dc1--topic1', Partition: 1, SeqNo: 4, partNo: 0, Offset: 2 is stored on disk
2025-10-26T18:07:24.558012Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 5  requestId: <none> cookie: 3
2025-10-26T18:07:24.558082Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::TEvPersQueue::TEvResponse
update user token request: { update_token_request { token: "topic1@builtin" } }
2025-10-26T18:07:24.559111Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read done: success: 1 data:  update_token_request [content omitted]
request: { write_request { sequence_numbers: 5 created_at_ms: 1761502044559 sent_at_ms: 1761502044559 message_sizes: 16 blocks_offsets: 0 blocks_part_numbers: 0 blocks_message_counts: 1 blocks_uncompressed_sizes: 16 blocks_headers: "\000" blocks_data: "valuevaluevalue1" } }
2025-10-26T18:07:24.560003Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-10-26T18:07:24.560234Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-10-26T18:07:24.560547Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.560574Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.560649Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 6  requestId: <none> cookie: 4
2025-10-26T18:07:24.560700Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-10-26T18:07:24.560916Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.560934Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 1
2025-10-26T18:07:24.560978Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message topic: rt3.dc1--topic1 partition: 1 SourceId: '\0source1' SeqNo: 5 partNo : 0 messageNo: 7 size 104 offset: -1
2025-10-26T18:07:24.561118Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 part blob processing sourceId '\0source1' seqNo 5 partNo 0
2025-10-26T18:07:24.562604Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 1 part blob complete sourceId '\0source1' seqNo 5 partNo 0 FormedBlobsCount 0 NewHead: Offset 3 PartNo 0 PackedSize 179 count 1 nextOffset 4 batches 1
2025-10-26T18:07:24.563200Z node 11 :PERSQUEUE DEBUG: Add new write blob: topic 'rt3.dc1--topic1' partition 1 compactOffset 3,1 HeadOffset 0 endOffset 3 curOffset 4 d0000000001_00000000000000000003_00000_0000000001_00000| size 167 WTime 1761502044562
2025-10-26T18:07:24.563419Z node 11 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-10-26T18:07:24.564769Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 1, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 112 WriteNewSizeFromSupportivePartitions# 0
2025-10-26T18:07:24.564807Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyWrite. Partition: 1
2025-10-26T18:07:24.564847Z node 11 :PERSQUEUE DEBUG: Answering for message sourceid: '\0source1', Topic: 'rt3.dc1--topic1', Partition: 1, SeqNo: 5, partNo: 0, Offset: 3 is stored on disk
2025-10-26T18:07:24.564868Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 1 messageNo: 7  requestId: <none> cookie: 4
2025-10-26T18:07:24.564924Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NKikimr::TEvPersQueue::TEvResponse
1 0 
2025-10-26T18:07:24.565767Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read done: success: 0 data: 
2025-10-26T18:07:24.565786Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 grpc read failed
2025-10-26T18:07:24.565964Z node 11 :PQ_WRITE_PROXY INFO: session v1 closed cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0
2025-10-26T18:07:24.565985Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: source1|2d8b9147-2a8fd89b-736d225a-5da5e4bc_0 is DEAD
2025-10-26T18:07:24.566392Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=1) Received event: NActors::TEvents::TEvPoison
2025-10-26T18:07:24.566806Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server disconnected, pipe [11:7565593674066564268:4267] destroyed
2025-10-26T18:07:24.566847Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 1, State: StateIdle] TPartition::DropOwner.
2025-10-26T18:07:24.567376Z node 11 :TICKET_PARSER ERROR: Ticket **** (E7252F7C): Could not find correct token validator
2025-10-26T18:07:24.567450Z node 11 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-10-26T18:07:24.567465Z node 11 :PQ_WRITE_PROXY DEBUG: new session created cookie 6
2025-10-26T18:07:24.567780Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 6 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic1" message_group_id: "source1" session_meta { key: "key" value: "value" } }
2025-10-26T18:07:24.567916Z node 11 :PQ_WRITE_PROXY INFO: session request cookie: 6 topic: "topic1" message_group_id: "source1" session_meta { key: "key" value: "value" } from ipv6:[::1]:51370
2025-10-26T18:07:24.567935Z node 11 :PQ_WRITE_PROXY INFO: write session:  cookie=6 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:51370 proto=v1  topic=topic1 durationSec=0
16 unauthenticated, Unauthenticated access is forbidden, please provide credentials
{  }
2025-10-26T18:07:24.568113Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 6 sessionId:  is DEAD
2025-10-26T18:07:24.579480Z :DEBUG: [] MessageGroupId [123] SessionId [] Write session: try to update token
2025-10-26T18:07:24.579956Z :INFO: [] MessageGroupId [123] SessionId [] Write session: Do CDS request
2025-10-26T18:07:24.579993Z :INFO: [] MessageGroupId [123] SessionId [] Start write session. Will connect to endpoint: localhost:15705
2025-10-26T18:07:24.588129Z :DEBUG: [] MessageGroupId [123] SessionId [] Write session: send init request: init_request { topic: "topic1" message_group_id: "123" }
2025-10-26T18:07:24.589569Z node 11 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-10-26T18:07:24.589604Z node 11 :PQ_WRITE_PROXY DEBUG: new session created cookie 7
2025-10-26T18:07:24.589971Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 7 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic1" message_group_id: "123" }
2025-10-26T18:07:24.590109Z node 11 :PQ_WRITE_PROXY INFO: session request cookie: 7 topic: "topic1" message_group_id: "123" from ipv6:[::1]:51454
2025-10-26T18:07:24.590135Z node 11 :PQ_WRITE_PROXY INFO: write session:  cookie=7 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:51454 proto=v1  topic=topic1 durationSec=0
2025-10-26T18:07:24.590146Z node 11 :PQ_WRITE_PROXY INFO: init check schema
2025-10-26T18:07:24.591940Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 7 sessionId:  describe result for acl check
2025-10-26T18:07:24.592133Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint32; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `/Root/PQ/SourceIdMeta2` WHERE Hash == $Hash AND Topic == $Topic AND SourceId == $SourceId;
2025-10-26T18:07:24.592149Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;DECLARE $SeqNo AS Uint64;
UPSERT INTO `/Root/PQ/SourceIdMeta2` (Hash, Topic, SourceId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-10-26T18:07:24.592165Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `/Root/PQ/SourceIdMeta2` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND SourceId = $SourceId AND Partition = $Partition;
2025-10-26T18:07:24.592187Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564306:4289] (SourceId=123, PreferedPartition=(NULL)) StartKqpSession
2025-10-26T18:07:24.595157Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564306:4289] (SourceId=123, PreferedPartition=(NULL)) Select from the table
2025-10-26T18:07:24.600258Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564306:4289] (SourceId=123, PreferedPartition=(NULL)) RequestPQRB
2025-10-26T18:07:24.600560Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic rt3.dc1--topic1 pipe [11:7565593674066564322:4289] connected; active server actors: 1
2025-10-26T18:07:24.600610Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564306:4289] (SourceId=123, PreferedPartition=(NULL)) Received partition 0 from PQRB for SourceId=123
2025-10-26T18:07:24.600633Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564306:4289] (SourceId=123, PreferedPartition=(NULL)) Update the table
2025-10-26T18:07:24.601066Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic rt3.dc1--topic1 pipe [11:7565593674066564322:4289] disconnected; active server actors: 1
2025-10-26T18:07:24.601092Z node 11 :PERSQUEUE_READ_BALANCER INFO: balancer: [72075186224037893] topic rt3.dc1--topic1 pipe [11:7565593674066564322:4289] disconnected no session
2025-10-26T18:07:24.606131Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564306:4289] (SourceId=123, PreferedPartition=(NULL)) HandleUpdate PartitionPersisted=0 Status=SUCCESS
2025-10-26T18:07:24.606178Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564306:4289] (SourceId=123, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=(NULL)
2025-10-26T18:07:24.606201Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564306:4289] (SourceId=123, PreferedPartition=(NULL)) Start idle
2025-10-26T18:07:24.606234Z node 11 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 7 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-10-26T18:07:24.607030Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 11, Generation: 1
2025-10-26T18:07:24.607080Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server connected, pipe [11:7565593674066564334:4289], now have 1 active actors on pipe
2025-10-26T18:07:24.607125Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.607146Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.607221Z node 11 :PERSQUEUE INFO: new Cookie 123|fc219960-d024e824-9be0e558-3e354e00_0 generated for partition 0 topic 'rt3.dc1--topic1' owner 123
2025-10-26T18:07:24.607276Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyOwnerOk. Partition: 0
2025-10-26T18:07:24.607320Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.607417Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.607428Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.607486Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.607576Z node 11 :PQ_WRITE_PROXY INFO: session inited cookie: 7 partition: 0 MaxSeqNo: 0 sessionId: 123|fc219960-d024e824-9be0e558-3e354e00_0
2025-10-26T18:07:24.610005Z :INFO: [] MessageGroupId [123] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1761502044609 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-10-26T18:07:24.610155Z :INFO: [] MessageGroupId [123] SessionId [] Write session established. Init response: session_id: "123|fc219960-d024e824-9be0e558-3e354e00_0" topic: "topic1" cluster: "dc1" supported_codecs: CODEC_RAW supported_codecs: CODEC_GZIP supported_codecs: CODEC_LZOP
ReadyToAcceptEvent
2025-10-26T18:07:24.610426Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write 1 messages with Id from 1 to 1
ReadyToAcceptEvent
2025-10-26T18:07:24.611272Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write session: try to update token
2025-10-26T18:07:24.611329Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Send 1 message(s) (0 left), first sequence number is 1
2025-10-26T18:07:24.611879Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 7 sessionId: 123|fc219960-d024e824-9be0e558-3e354e00_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-10-26T18:07:24.612090Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-10-26T18:07:24.612222Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.612249Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.612322Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-10-26T18:07:24.612361Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-10-26T18:07:24.612428Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.612440Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.612483Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message topic: rt3.dc1--topic1 partition: 0 SourceId: '\000123' SeqNo: 1 partNo : 0 messageNo: 1 size 92 offset: -1
2025-10-26T18:07:24.612604Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 0 part blob processing sourceId '\000123' seqNo 1 partNo 0
2025-10-26T18:07:24.613802Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 0 part blob complete sourceId '\000123' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 163 count 1 nextOffset 1 batches 1
2025-10-26T18:07:24.614256Z node 11 :PERSQUEUE DEBUG: Add new write blob: topic 'rt3.dc1--topic1' partition 0 compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 d0000000000_00000000000000000000_00000_0000000001_00000| size 151 WTime 1761502044613
2025-10-26T18:07:24.614437Z node 11 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-10-26T18:07:24.616292Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 96 WriteNewSizeFromSupportivePartitions# 0
2025-10-26T18:07:24.616329Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyWrite. Partition: 0
2025-10-26T18:07:24.616360Z node 11 :PERSQUEUE DEBUG: Answering for message sourceid: '\000123', Topic: 'rt3.dc1--topic1', Partition: 0, SeqNo: 1, partNo: 0, Offset: 0 is stored on disk
2025-10-26T18:07:24.616473Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 0 user user readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-10-26T18:07:24.616486Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 0 user user send read request for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 1 rrg 0
2025-10-26T18:07:24.616545Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-10-26T18:07:24.616631Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-10-26T18:07:24.616758Z node 11 :PERSQUEUE DEBUG: read cookie 0 Topic 'rt3.dc1--topic1' partition 0 user user offset 0 count 1 size 1024000 endOffset 1 max time lag 0ms effective offset 0
2025-10-26T18:07:24.616774Z node 11 :PERSQUEUE DEBUG: read cookie 0 added 0 blobs, size 0 count 0 last offset 0
2025-10-26T18:07:24.616794Z node 11 :PERSQUEUE DEBUG: Reading cookie 0. All data is from uncompacted head.
2025-10-26T18:07:24.616808Z node 11 :PERSQUEUE DEBUG: FormAnswer 0
2025-10-26T18:07:24.616876Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 0 user user readTimeStamp done, result 1761502044612 queuesize 0 startOffset 0
2025-10-26T18:07:24.618270Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write session got write response: sequence_numbers: 1 offsets: 0 already_written: false write_statistics { persist_duration_ms: 2 queued_in_partition_duration_ms: 1 }
2025-10-26T18:07:24.618315Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write session: acknoledged message 1
AcksEvent: { seqNo : 1, State : EES_WRITTEN, offset : 0, partitionId : 0 } write stat: Write time 0.002000s total time in partition queue 0.001000s partition quoted time 0.000000s topic quoted time 0.000000s
Set token user_without_rights@builtin
2025-10-26T18:07:24.619394Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write 1 messages with Id from 2 to 2
ReadyToAcceptEvent
2025-10-26T18:07:24.619655Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write session: try to update token
2025-10-26T18:07:24.619698Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write session: updating token
2025-10-26T18:07:24.619947Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Send 1 message(s) (0 left), first sequence number is 2
2025-10-26T18:07:24.620222Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 7 sessionId: 123|fc219960-d024e824-9be0e558-3e354e00_0 grpc read done: success: 1 data:  update_token_request [content omitted]
2025-10-26T18:07:24.620789Z node 11 :PQ_WRITE_PROXY INFO: updating token
2025-10-26T18:07:24.620837Z node 11 :PQ_WRITE_PROXY INFO: init check schema
2025-10-26T18:07:24.621651Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 7 sessionId: 123|fc219960-d024e824-9be0e558-3e354e00_0 describe result for acl check
2025-10-26T18:07:24.621727Z node 11 :PQ_WRITE_PROXY INFO: session v1 error cookie: 7 reason: access to topic 'Topic topic1 in dc dc1' denied for 'user_without_rights@builtin' due to 'no WriteTopic rights', Marker# PQ1125 sessionId: 123|fc219960-d024e824-9be0e558-3e354e00_0
2025-10-26T18:07:24.621856Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 7 sessionId: 123|fc219960-d024e824-9be0e558-3e354e00_0 is DEAD
2025-10-26T18:07:24.622220Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-10-26T18:07:24.622346Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server disconnected, pipe [11:7565593674066564334:4289] destroyed
2025-10-26T18:07:24.622390Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-10-26T18:07:24.623114Z :ERROR: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Got error. Status: UNAUTHORIZED. Description: <main>: Error: access to topic 'Topic topic1 in dc dc1' denied for 'user_without_rights@builtin' due to 'no WriteTopic rights', Marker# PQ1125, code: 500018 
2025-10-26T18:07:24.623146Z :ERROR: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write session will not restart after a fatal error
2025-10-26T18:07:24.623179Z :INFO: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write session will now close
2025-10-26T18:07:24.623215Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write session: aborting
SessionClosed { Status: UNAUTHORIZED Issues: "<main>: Error: access to topic 'Topic topic1 in dc dc1' denied for 'user_without_rights@builtin' due to 'no WriteTopic rights', Marker# PQ1125, code: 500018 " }
2025-10-26T18:07:24.623678Z :DEBUG: [] MessageGroupId [123] SessionId [123|fc219960-d024e824-9be0e558-3e354e00_0] Write session: destroy
2025-10-26T18:07:24.634182Z :DEBUG: [] MessageGroupId [123] SessionId [] Write session: try to update token
2025-10-26T18:07:24.634507Z :INFO: [] MessageGroupId [123] SessionId [] Write session: Do CDS request
2025-10-26T18:07:24.634528Z :INFO: [] MessageGroupId [123] SessionId [] Start write session. Will connect to endpoint: localhost:15705
2025-10-26T18:07:24.640778Z :DEBUG: [] MessageGroupId [123] SessionId [] Write session: send init request: init_request { topic: "topic1" message_group_id: "123" }
2025-10-26T18:07:24.641769Z node 11 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-10-26T18:07:24.641807Z node 11 :PQ_WRITE_PROXY DEBUG: new session created cookie 8
2025-10-26T18:07:24.642179Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 8 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic1" message_group_id: "123" }
2025-10-26T18:07:24.642307Z node 11 :PQ_WRITE_PROXY INFO: session request cookie: 8 topic: "topic1" message_group_id: "123" from ipv6:[::1]:51464
2025-10-26T18:07:24.642327Z node 11 :PQ_WRITE_PROXY INFO: write session:  cookie=8 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:51464 proto=v1  topic=topic1 durationSec=0
2025-10-26T18:07:24.642336Z node 11 :PQ_WRITE_PROXY INFO: init check schema
2025-10-26T18:07:24.643941Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 8 sessionId:  describe result for acl check
2025-10-26T18:07:24.644143Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint32; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `/Root/PQ/SourceIdMeta2` WHERE Hash == $Hash AND Topic == $Topic AND SourceId == $SourceId;
2025-10-26T18:07:24.644178Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;DECLARE $SeqNo AS Uint64;
UPSERT INTO `/Root/PQ/SourceIdMeta2` (Hash, Topic, SourceId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-10-26T18:07:24.644195Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint32; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `/Root/PQ/SourceIdMeta2` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND SourceId = $SourceId AND Partition = $Partition;
2025-10-26T18:07:24.644219Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564351:4273] (SourceId=123, PreferedPartition=(NULL)) StartKqpSession
2025-10-26T18:07:24.646511Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564351:4273] (SourceId=123, PreferedPartition=(NULL)) Select from the table
2025-10-26T18:07:24.651600Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564351:4273] (SourceId=123, PreferedPartition=(NULL)) Update the table
2025-10-26T18:07:24.657558Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564351:4273] (SourceId=123, PreferedPartition=(NULL)) HandleUpdate PartitionPersisted=0 Status=SUCCESS
2025-10-26T18:07:24.657611Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564351:4273] (SourceId=123, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-10-26T18:07:24.657636Z node 11 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [11:7565593674066564351:4273] (SourceId=123, PreferedPartition=(NULL)) Start idle
2025-10-26T18:07:24.657670Z node 11 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 8 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-10-26T18:07:24.658813Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 11, Generation: 1
2025-10-26T18:07:24.658866Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server connected, pipe [11:7565593674066564374:4273], now have 1 active actors on pipe
2025-10-26T18:07:24.658996Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.659023Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.659094Z node 11 :PERSQUEUE INFO: new Cookie 123|611f295-764cc5a6-ca0067cd-b11bf6b8_0 generated for partition 0 topic 'rt3.dc1--topic1' owner 123
2025-10-26T18:07:24.659172Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyOwnerOk. Partition: 0
2025-10-26T18:07:24.659240Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.659436Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.659457Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.659528Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-10-26T18:07:24.659681Z node 11 :PQ_WRITE_PROXY INFO: session inited cookie: 8 partition: 0 MaxSeqNo: 1 sessionId: 123|611f295-764cc5a6-ca0067cd-b11bf6b8_0
2025-10-26T18:07:24.660372Z :INFO: [] MessageGroupId [123] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1761502044660 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-10-26T18:07:24.660516Z :INFO: [] MessageGroupId [123] SessionId [] Write session established. Init response: last_sequence_number: 1 session_id: "123|611f295-764cc5a6-ca0067cd-b11bf6b8_0" topic: "topic1" cluster: "dc1" supported_codecs: CODEC_RAW supported_codecs: CODEC_GZIP supported_codecs: CODEC_LZOP
ReadyToAcceptEvent
2025-10-26T18:07:24.660783Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write 1 messages with Id from 1 to 1
ReadyToAcceptEvent
2025-10-26T18:07:24.661038Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write session: try to update token
2025-10-26T18:07:24.661068Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Send 1 message(s) (0 left), first sequence number is 2
2025-10-26T18:07:24.661549Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 8 sessionId: 123|611f295-764cc5a6-ca0067cd-b11bf6b8_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-10-26T18:07:24.661856Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-10-26T18:07:24.661993Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.662015Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.662092Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-10-26T18:07:24.662147Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-10-26T18:07:24.662228Z node 11 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'rt3.dc1--topic1' requestId: <none>
2025-10-26T18:07:24.662244Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message batch for topic 'rt3.dc1--topic1' partition 0
2025-10-26T18:07:24.662290Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 got client message topic: rt3.dc1--topic1 partition: 0 SourceId: '\000123' SeqNo: 2 partNo : 0 messageNo: 1 size 92 offset: -1
2025-10-26T18:07:24.662429Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 0 part blob processing sourceId '\000123' seqNo 2 partNo 0
2025-10-26T18:07:24.663712Z node 11 :PERSQUEUE DEBUG: Topic 'rt3.dc1--topic1' partition 0 part blob complete sourceId '\000123' seqNo 2 partNo 0 FormedBlobsCount 0 NewHead: Offset 1 PartNo 0 PackedSize 163 count 1 nextOffset 2 batches 1
2025-10-26T18:07:24.664153Z node 11 :PERSQUEUE DEBUG: Add new write blob: topic 'rt3.dc1--topic1' partition 0 compactOffset 1,1 HeadOffset 0 endOffset 1 curOffset 2 d0000000000_00000000000000000001_00000_0000000001_00000| size 151 WTime 1761502044663
2025-10-26T18:07:24.664373Z node 11 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-10-26T18:07:24.665368Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 96 WriteNewSizeFromSupportivePartitions# 0
2025-10-26T18:07:24.665403Z node 11 :PERSQUEUE DEBUG: TPartition::ReplyWrite. Partition: 0
2025-10-26T18:07:24.665447Z node 11 :PERSQUEUE DEBUG: Answering for message sourceid: '\000123', Topic: 'rt3.dc1--topic1', Partition: 0, SeqNo: 2, partNo: 0, Offset: 1 is stored on disk
2025-10-26T18:07:24.665601Z node 11 :PERSQUEUE DEBUG: Answer ok topic: 'rt3.dc1--topic1' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-10-26T18:07:24.665671Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-10-26T18:07:24.666228Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write session got write response: sequence_numbers: 2 offsets: 1 already_written: false write_statistics { persist_duration_ms: 2 queued_in_partition_duration_ms: 1 }
2025-10-26T18:07:24.666262Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write session: acknoledged message 1
AcksEvent: { seqNo : 1, State : EES_WRITTEN, offset : 1, partitionId : 0 } write stat: Write time 0.002000s total time in partition queue 0.001000s partition quoted time 0.000000s topic quoted time 0.000000s
Set token invalid_ticket
2025-10-26T18:07:24.666509Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write 1 messages with Id from 2 to 2
ReadyToAcceptEvent
2025-10-26T18:07:24.666985Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write session: try to update token
2025-10-26T18:07:24.667032Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write session: updating token
2025-10-26T18:07:24.667282Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Send 1 message(s) (0 left), first sequence number is 3
2025-10-26T18:07:24.667410Z node 11 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 8 sessionId: 123|611f295-764cc5a6-ca0067cd-b11bf6b8_0 grpc read done: success: 1 data:  update_token_request [content omitted]
2025-10-26T18:07:24.667708Z node 11 :PQ_WRITE_PROXY INFO: updating token
2025-10-26T18:07:24.668549Z :ERROR: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Got error. Status: CLIENT_UNAUTHENTICATED. Description: <main>: Error: GRpc error: (16): unauthenticated, refreshed token is invalid 
2025-10-26T18:07:24.668592Z :ERROR: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write session will not restart after a fatal error
2025-10-26T18:07:24.668628Z :INFO: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write session will now close
2025-10-26T18:07:24.668680Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write session: aborting
2025-10-26T18:07:24.668016Z node 11 :PQ_WRITE_PROXY INFO: session v1 cookie: 8 sessionId: 123|611f295-764cc5a6-ca0067cd-b11bf6b8_0 is DEAD
2025-10-26T18:07:24.668454Z node 11 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
SessionClosed { Status: CLIENT_UNAUTHENTICATED Issues: "<main>: Error: GRpc error: (16): unauthenticated, refreshed token is invalid " }
2025-10-26T18:07:24.668986Z :DEBUG: [] MessageGroupId [123] SessionId [123|611f295-764cc5a6-ca0067cd-b11bf6b8_0] Write session: destroy
2025-10-26T18:07:24.670122Z node 11 :PERSQUEUE DEBUG: Tablet 72075186224037892 server disconnected, pipe [11:7565593674066564374:4273] destroyed
2025-10-26T18:07:24.670178Z node 11 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
