2025-11-05T13:42:33.052143Z node 2 :METADATA_PROVIDER WARN: fline=table_exists.cpp:54;actor=TTableExistsActor;event=undelivered;self_id=[2:7569236273755630401:2158];send_to=[0:7307199536658146131:7762515];
2025-11-05T13:42:33.053617Z node 2 :METADATA_PROVIDER ERROR: fline=accessor_snapshot_base.cpp:69;action=cannot detect path existence;path=//Root/.metadata/initialization/migrations;error=scheme_cache_undelivered_message;
2025-11-05T13:42:33.053789Z node 2 :PQ_READ_PROXY DEBUG: Direct read cache: : Created
test_client.cpp: SetPath # /home/runner/.ya/build/build_root/4xc1/003f89/r3tmp/tmp2saalX/pdisk_1.dat
TServer::EnableGrpc on GrpcPort 18634, node 2
2025-11-05T13:42:33.074366Z node 2 :IMPORT WARN: Table profiles were not loaded
2025-11-05T13:42:33.074607Z node 2 :CONFIGS_DISPATCHER ERROR: Notification cookie mismatch for subscription [2:7569236273755630259:2081] 1762350153049623 != 1762350153049626
2025-11-05T13:42:33.083470Z INFO: TTestServer started on Port 14257 GrpcPort 18634
2025-11-05T13:42:33.081655Z node 2 :NET_CLASSIFIER WARN: distributable config is empty, broken or outdated, will use file: /home/runner/.ya/build/build_root/4xc1/003f89/r3tmp/yandexC3ThsR.tmp
2025-11-05T13:42:33.081669Z node 2 :NET_CLASSIFIER WARN: will try to initialize from file: /home/runner/.ya/build/build_root/4xc1/003f89/r3tmp/yandexC3ThsR.tmp
2025-11-05T13:42:33.089516Z node 2 :NET_CLASSIFIER WARN: successfully initialized from file: /home/runner/.ya/build/build_root/4xc1/003f89/r3tmp/yandexC3ThsR.tmp
2025-11-05T13:42:33.089623Z node 2 :NET_CLASSIFIER ERROR: got bad distributable configuration
TClient is connected to server localhost:14257
PQClient connected to localhost:18634
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
    }
    ChildrenExist: false
  }
  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
      Pl...
(TRUNCATED)
WaitRootIsUp 'Root' success.
2025-11-05T13:42:33.157797Z node 2 :HIVE WARN: HIVE#72057594037968897 Node(2, (0,0,0,0)) VolatileState: Unknown -> Disconnected
2025-11-05T13:42:33.157820Z node 2 :HIVE WARN: HIVE#72057594037968897 Node(2, (0,0,0,0)) VolatileState: Disconnected -> Connecting
2025-11-05T13:42:33.158129Z node 2 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpAlterSubDomain, opId: 281474976715657:0, at schemeshard:  72057594046644480
waiting...
2025-11-05T13:42:33.158826Z node 2 :HIVE WARN: HIVE#72057594037968897 Node(2, (0,0,0,0)) VolatileState: Connecting -> Connected
waiting...
2025-11-05T13:42:33.173461Z node 2 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976715659:0, at schemeshard:  72057594046644480
waiting...
waiting...
waiting...
2025-11-05T13:42:33.400008Z node 2 :KQP_COMPILE_ACTOR ERROR: Compilation failed, self: [2:7569236273755631024:2316], 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-11-05T13:42:33.400434Z node 2 :KQP_SESSION WARN: SessionId: ydb://session/3?node_id=2&id=ZDNkOGExZWEtOWY4YjI5MjgtYWZlODRlMDAtY2MyZjgxMjY=, ActorId: [2:7569236273755631021:2314], ActorState: ExecuteState, TraceId: 01k9a42fnkbbga1m3dtw9tddn5, ReplyQueryCompileError, status SCHEME_ERROR remove tx with tx_id: 
2025-11-05T13:42:33.400562Z node 2 :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-11-05T13:42:33.403528Z node 2 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976715662:0, at schemeshard:  72057594046644480
2025-11-05T13:42:33.412007Z node 2 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976715663:0, at schemeshard:  72057594046644480
2025-11-05T13:42:33.435847Z node 2 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976715664: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);
=== CheckClustersList. Subcribe to ClusterTracker from [2:7569236273755631297:2561] 
2025-11-05T13:42:34.052598Z node 2 :TX_CONVEYOR ERROR: fline=service.h:53;problem=unexpected event for task executor;ev_type=NActors::TEvents::TEvWakeup;
2025-11-05T13:42:38.051814Z node 2 :METADATA_PROVIDER ERROR: fline=table_exists.cpp:59;actor=TTableExistsActor;event=timeout;self_id=[2:7569236273755630401:2158];send_to=[0:7307199536658146131:7762515];
2025-11-05T13:42:38.051858Z node 2 :METADATA_PROVIDER ERROR: fline=accessor_snapshot_base.cpp:69;action=cannot detect path existence;path=//Root/.metadata/initialization/migrations;error=timeout;
=== CheckClustersList. Ok
2025-11-05T13:42:38.593040Z :WriteToTopic_Demo_34 INFO: TTopicSdkTestSetup started
2025-11-05T13:42:38.617765Z node 2 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:42:38.623242Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:42:38.623395Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][] pipe [2:7569236295230468095:2741] connected; active server actors: 1
2025-11-05T13:42:38.623459Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:42:38.623483Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:38.623546Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:42:38.623597Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] doesn't have tx info
2025-11-05T13:42:38.623607Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:42:38.623611Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] no config, start with empty partitions and default config
2025-11-05T13:42:38.623615Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:42:38.623622Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:38.623623Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:38.623635Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892] doesn't have tx writes info
2025-11-05T13:42:38.623643Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] BALANCER INIT DONE for test-topic: (0, 72075186224037892) 
2025-11-05T13:42:38.623754Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236295230468094:2740], now have 1 active actors on pipe
2025-11-05T13:42:38.623867Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72075186224037892, NodeId 2, Generation 1
2025-11-05T13:42:38.623878Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72057594046644480, NodeId 2, Generation 2
2025-11-05T13:42:38.623947Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } TxId: 281474976715671 Config { TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 } } }
2025-11-05T13:42:38.623982Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] Propose TxId 281474976715671, WriteId (empty maybe)
2025-11-05T13:42:38.623993Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state UNKNOWN
2025-11-05T13:42:38.623995Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State UNKNOWN
2025-11-05T13:42:38.623999Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:42:38.624002Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from UNKNOWN to PREPARING
2025-11-05T13:42:38.624009Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:38.624056Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PREPARED MinStep: 1762350158639 MaxStep: 18446744073709551615 Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } Partitions { }
2025-11-05T13:42:38.624090Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.624101Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236295230468123:2422], now have 1 active actors on pipe
2025-11-05T13:42:38.624255Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.624269Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARING
2025-11-05T13:42:38.624271Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARING
2025-11-05T13:42:38.624273Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARING to PREPARED
2025-11-05T13:42:38.624828Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037892 TxId: 281474976715671
2025-11-05T13:42:38.624847Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236295230468134:2763], now have 1 active actors on pipe
2025-11-05T13:42:38.624863Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715671 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350158674 MediatorID: 72057594046382081 TabletID: 72075186224037892
2025-11-05T13:42:38.624870Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARED
2025-11-05T13:42:38.624872Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARED
2025-11-05T13:42:38.624875Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARED to PLANNING
2025-11-05T13:42:38.624879Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] PlanStep 1762350158674, PlanTxId 281474976715671
2025-11-05T13:42:38.624883Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:38.624948Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PLANNED MinStep: 1762350158639 MaxStep: 18446744073709551615 Step: 1762350158674 Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } Partitions { }
2025-11-05T13:42:38.624965Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.625405Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.625413Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PLANNING
2025-11-05T13:42:38.625415Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PLANNING
2025-11-05T13:42:38.625417Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNING to PLANNED
2025-11-05T13:42:38.625421Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxQueue.size 1
2025-11-05T13:42:38.626129Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] New ExecStep 1762350158674, ExecTxId 281474976715671
2025-11-05T13:42:38.626248Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNED to CALCULATING
2025-11-05T13:42:38.626264Z node 2 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:42:38.626274Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:42:38.626359Z node 2 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:42:38.626409Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] bootstrapping 0 [2:7569236295230468141:2426]
2025-11-05T13:42:38.626645Z node 2 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Initializing completed.
2025-11-05T13:42:38.626649Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] init complete for topic 'test-topic' partition 0 generation 1 [2:7569236295230468141:2426]
2025-11-05T13:42:38.626657Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateInit] SYNC INIT topic test-topic partitition 0 so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:42:38.626728Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:42:38.626734Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.626754Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.626758Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:38.626760Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.626761Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.626763Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:38.626771Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 user test-consumer readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:42:38.626927Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350158674, TxId 281474976715671, Partition 0
2025-11-05T13:42:38.626933Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] Handle TEvProposePartitionConfigResult
2025-11-05T13:42:38.626937Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] Partition responses 1/1
2025-11-05T13:42:38.626939Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATING
2025-11-05T13:42:38.626940Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATING
2025-11-05T13:42:38.626942Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATING FrontTxId 281474976715671
2025-11-05T13:42:38.626946Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:42:38.626948Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATING to CALCULATED
2025-11-05T13:42:38.626951Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:38.627026Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: CALCULATED MinStep: 1762350158639 MaxStep: 18446744073709551615 Step: 1762350158674 Predicate: true Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:38.627042Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.627185Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.627186Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATED
2025-11-05T13:42:38.627187Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATED
2025-11-05T13:42:38.627189Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATED FrontTxId 281474976715671
2025-11-05T13:42:38.627190Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATED to WAIT_RS
2025-11-05T13:42:38.627199Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:42:38.627202Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveParticipantsDecision 1
2025-11-05T13:42:38.627208Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS to EXECUTING
2025-11-05T13:42:38.627209Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 0, Expected 1
2025-11-05T13:42:38.627216Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350158674, TxId 281474976715671
2025-11-05T13:42:38.627219Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.627221Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.627243Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.627269Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.627484Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] Handle TEvPQ::TEvTxCommitDone Step 1762350158674, TxId 281474976715671, Partition 0
2025-11-05T13:42:38.627490Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTING
2025-11-05T13:42:38.627491Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTING
2025-11-05T13:42:38.627493Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTING FrontTxId 281474976715671
2025-11-05T13:42:38.627494Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:42:38.627499Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId: 281474976715671 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:42:38.627506Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] complete TxId 281474976715671
2025-11-05T13:42:38.627548Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Apply new config PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 }
2025-11-05T13:42:38.627562Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:38.627570Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] delete partitions for TxId 281474976715671
2025-11-05T13:42:38.627575Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTING to EXECUTED
2025-11-05T13:42:38.627578Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:38.627618Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: EXECUTED MinStep: 1762350158639 MaxStep: 18446744073709551615 Step: 1762350158674 Predicate: true Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:38.627641Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.627890Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.627897Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTED
2025-11-05T13:42:38.627899Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTED
2025-11-05T13:42:38.627899Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:38.627901Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTED FrontTxId 281474976715671
2025-11-05T13:42:38.627904Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:42:38.627904Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.627906Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.627906Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:42:38.627909Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:42:38.627911Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:42:38.627921Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:42:38.627924Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] add an TxId 281474976715671 to the list for deletion
2025-11-05T13:42:38.627926Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:42:38.627929Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] delete key for TxId 281474976715671
2025-11-05T13:42:38.627937Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.628247Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.628253Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state DELETING
2025-11-05T13:42:38.628254Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State DELETING
2025-11-05T13:42:38.628257Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] delete TxId 281474976715671
2025-11-05T13:42:38.628328Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:38.628357Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:38.629581Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:42:38.629867Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:42:38.629875Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:18634
2025-11-05T13:42:38.634675Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "test-topic" message_group_id: "src" }
2025-11-05T13:42:38.637717Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:38.637733Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 1
2025-11-05T13:42:38.637892Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId:  grpc read done: success: 1 data: init_request { topic: "test-topic" message_group_id: "src" }
2025-11-05T13:42:38.637914Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 1 topic: "test-topic" message_group_id: "src" from ipv6:[::1]:49786
2025-11-05T13:42:38.637919Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=1 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:49786 proto=v1  topic=test-topic durationSec=0
2025-11-05T13:42:38.637923Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:38.638934Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId:  describe result for acl check
2025-11-05T13:42:38.638957Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint64; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `//Root/.metadata/TopicPartitionsMapping` WHERE Hash == $Hash AND Topic == $Topic AND ProducerId == $SourceId;
2025-11-05T13:42:38.638958Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64; DECLARE $SeqNo AS Uint64;
UPSERT INTO `//Root/.metadata/TopicPartitionsMapping` (Hash, Topic, ProducerId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-11-05T13:42:38.638959Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `//Root/.metadata/TopicPartitionsMapping` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND ProducerId = $SourceId AND Partition = $Partition;
2025-11-05T13:42:38.638966Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236295230468185:2434] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:38.638968Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 1 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:38.639273Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 2, Generation: 1
2025-11-05T13:42:38.639291Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236295230468188:2434], now have 1 active actors on pipe
2025-11-05T13:42:38.639369Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:38.639375Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:38.639392Z node 2 :PERSQUEUE INFO: new Cookie src|5803c389-70e767bd-d83cef9b-d0c4d7b_0 generated for partition 0 topic 'test-topic' owner src
2025-11-05T13:42:38.639401Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.639404Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.639414Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.639421Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:38.639432Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.639527Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:38.639532Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:38.639547Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.639561Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 1 partition: 0 MaxSeqNo: 0 sessionId: src|5803c389-70e767bd-d83cef9b-d0c4d7b_0
2025-11-05T13:42:38.641681Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350158641 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:38.641720Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|5803c389-70e767bd-d83cef9b-d0c4d7b_0" topic: "test-topic"
2025-11-05T13:42:38.641881Z :INFO: [/Root] MessageGroupId [src] SessionId [src|5803c389-70e767bd-d83cef9b-d0c4d7b_0] Write session: close. Timeout = 0 ms
2025-11-05T13:42:38.641885Z :INFO: [/Root] MessageGroupId [src] SessionId [src|5803c389-70e767bd-d83cef9b-d0c4d7b_0] Write session will now close
2025-11-05T13:42:38.641889Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|5803c389-70e767bd-d83cef9b-d0c4d7b_0] Write session: aborting
2025-11-05T13:42:38.641985Z :INFO: [/Root] MessageGroupId [src] SessionId [src|5803c389-70e767bd-d83cef9b-d0c4d7b_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:38.641990Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|5803c389-70e767bd-d83cef9b-d0c4d7b_0] Write session: destroy
2025-11-05T13:42:38.645673Z :WriteToTopic_Demo_34 INFO: Topic created
2025-11-05T13:42:38.645518Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId: src|5803c389-70e767bd-d83cef9b-d0c4d7b_0 grpc read done: success: 0 data: 
2025-11-05T13:42:38.645533Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|5803c389-70e767bd-d83cef9b-d0c4d7b_0 grpc read failed
2025-11-05T13:42:38.645548Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|5803c389-70e767bd-d83cef9b-d0c4d7b_0 grpc closed
2025-11-05T13:42:38.645551Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|5803c389-70e767bd-d83cef9b-d0c4d7b_0 is DEAD
2025-11-05T13:42:38.645765Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:38.646006Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [2:7569236295230468188:2434] destroyed
2025-11-05T13:42:38.646020Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:38.646025Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.646027Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.650174Z node 2 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:42:38.652081Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:38.653139Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:38.654500Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:42:38.654602Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][] pipe [2:7569236295230468223:2802] connected; active server actors: 1
2025-11-05T13:42:38.654646Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:42:38.654878Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:42:38.654925Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:42:38.654962Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] doesn't have tx info
2025-11-05T13:42:38.654965Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:42:38.654967Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] no config, start with empty partitions and default config
2025-11-05T13:42:38.654971Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:42:38.654977Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:38.654987Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894] doesn't have tx writes info
2025-11-05T13:42:38.655015Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:42:38.655029Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] BALANCER INIT DONE for topic_A: (0, 72075186224037894) 
2025-11-05T13:42:38.655298Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236295230468222:2801], now have 1 active actors on pipe
2025-11-05T13:42:38.655398Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } TxId: 281474976715672 Config { TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 } } }
2025-11-05T13:42:38.655424Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Propose TxId 281474976715672, WriteId (empty maybe)
2025-11-05T13:42:38.655430Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state UNKNOWN
2025-11-05T13:42:38.655433Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State UNKNOWN
2025-11-05T13:42:38.655438Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:42:38.655441Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from UNKNOWN to PREPARING
2025-11-05T13:42:38.655448Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:42:38.655502Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PREPARED MinStep: 1762350158681 MaxStep: 18446744073709551615 Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } Partitions { }
2025-11-05T13:42:38.655521Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.655750Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236295230468265:2449], now have 1 active actors on pipe
2025-11-05T13:42:38.655806Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientConnected TabletId 72075186224037894, NodeId 2, Generation 1
2025-11-05T13:42:38.655809Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientConnected TabletId 72057594046644480, NodeId 2, Generation 2
2025-11-05T13:42:38.655961Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.655970Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARING
2025-11-05T13:42:38.655972Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARING
2025-11-05T13:42:38.655974Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARING to PREPARED
2025-11-05T13:42:38.656495Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037894 TxId: 281474976715672
2025-11-05T13:42:38.656506Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236295230468276:2831], now have 1 active actors on pipe
2025-11-05T13:42:38.656522Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715672 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350158702 MediatorID: 72057594046382081 TabletID: 72075186224037894
2025-11-05T13:42:38.656527Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARED
2025-11-05T13:42:38.656528Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARED
2025-11-05T13:42:38.656530Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARED to PLANNING
2025-11-05T13:42:38.656534Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] PlanStep 1762350158702, PlanTxId 281474976715672
2025-11-05T13:42:38.656537Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:42:38.656602Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PLANNED MinStep: 1762350158681 MaxStep: 18446744073709551615 Step: 1762350158702 Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } Partitions { }
2025-11-05T13:42:38.656616Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.656910Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.656916Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PLANNING
2025-11-05T13:42:38.656918Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PLANNING
2025-11-05T13:42:38.656920Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNING to PLANNED
2025-11-05T13:42:38.656924Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxQueue.size 1
2025-11-05T13:42:38.656926Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] New ExecStep 1762350158702, ExecTxId 281474976715672
2025-11-05T13:42:38.657022Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNED to CALCULATING
2025-11-05T13:42:38.657034Z node 2 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:42:38.657043Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:42:38.657082Z node 2 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:42:38.657127Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] bootstrapping 0 [2:7569236295230468282:2452]
2025-11-05T13:42:38.657331Z node 2 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Initializing completed.
2025-11-05T13:42:38.657334Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] init complete for topic 'topic_A' partition 0 generation 1 [2:7569236295230468282:2452]
2025-11-05T13:42:38.657341Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateInit] SYNC INIT topic topic_A partitition 0 so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:42:38.657416Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:42:38.657421Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.657454Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.657457Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:38.657459Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.657460Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.657462Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:38.657469Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:42:38.657508Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350158702, TxId 281474976715672, Partition 0
2025-11-05T13:42:38.657510Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] Handle TEvProposePartitionConfigResult
2025-11-05T13:42:38.657513Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] Partition responses 1/1
2025-11-05T13:42:38.657515Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATING
2025-11-05T13:42:38.657517Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATING
2025-11-05T13:42:38.657519Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATING FrontTxId 281474976715672
2025-11-05T13:42:38.657522Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:42:38.657525Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATING to CALCULATED
2025-11-05T13:42:38.657528Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:42:38.657598Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: CALCULATED MinStep: 1762350158681 MaxStep: 18446744073709551615 Step: 1762350158702 Predicate: true Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:38.657612Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.658066Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.658071Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATED
2025-11-05T13:42:38.658072Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATED
2025-11-05T13:42:38.658074Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATED FrontTxId 281474976715672
2025-11-05T13:42:38.658076Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATED to WAIT_RS
2025-11-05T13:42:38.658085Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:42:38.658088Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveParticipantsDecision 1
2025-11-05T13:42:38.658094Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS to EXECUTING
2025-11-05T13:42:38.658096Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 0, Expected 1
2025-11-05T13:42:38.658104Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350158702, TxId 281474976715672
2025-11-05T13:42:38.658107Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.658108Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.658130Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.658157Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.658602Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:38.658611Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.658612Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.658632Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTxCommitDone Step 1762350158702, TxId 281474976715672, Partition 0
2025-11-05T13:42:38.658635Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTING
2025-11-05T13:42:38.658636Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTING
2025-11-05T13:42:38.658637Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTING FrontTxId 281474976715672
2025-11-05T13:42:38.658640Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:42:38.658644Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId: 281474976715672 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:42:38.658650Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] complete TxId 281474976715672
2025-11-05T13:42:38.658692Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Apply new config PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 }
2025-11-05T13:42:38.658703Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:38.658708Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] delete partitions for TxId 281474976715672
2025-11-05T13:42:38.658710Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTING to EXECUTED
2025-11-05T13:42:38.658713Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:42:38.658754Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: EXECUTED MinStep: 1762350158681 MaxStep: 18446744073709551615 Step: 1762350158702 Predicate: true Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236273755630606 RawX2: 8589936740 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:38.658776Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.660037Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:38.660053Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:42:38.660303Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:38.660309Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:42:38.660333Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.660336Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTED
2025-11-05T13:42:38.660337Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTED
2025-11-05T13:42:38.660339Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTED FrontTxId 281474976715672
2025-11-05T13:42:38.660342Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:42:38.660344Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:42:38.660347Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:42:38.660349Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:42:38.660350Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:42:38.660352Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] add an TxId 281474976715672 to the list for deletion
2025-11-05T13:42:38.660354Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:42:38.660357Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] delete key for TxId 281474976715672
2025-11-05T13:42:38.660363Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.660610Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.660614Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state DELETING
2025-11-05T13:42:38.660616Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State DELETING
2025-11-05T13:42:38.660618Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] delete TxId 281474976715672
2025-11-05T13:42:38.661941Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:42:38.662191Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:42:38.662197Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:18634
2025-11-05T13:42:38.666978Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:42:38.667452Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:38.667461Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 2
2025-11-05T13:42:38.667599Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:42:38.667618Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 2 topic: "topic_A" message_group_id: "src" from ipv6:[::1]:49786
2025-11-05T13:42:38.667624Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=2 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:49786 proto=v1  topic=topic_A durationSec=0
2025-11-05T13:42:38.667626Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:38.668190Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId:  describe result for acl check
2025-11-05T13:42:38.668220Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint64; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `//Root/.metadata/TopicPartitionsMapping` WHERE Hash == $Hash AND Topic == $Topic AND ProducerId == $SourceId;
2025-11-05T13:42:38.668222Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64; DECLARE $SeqNo AS Uint64;
UPSERT INTO `//Root/.metadata/TopicPartitionsMapping` (Hash, Topic, ProducerId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-11-05T13:42:38.668223Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `//Root/.metadata/TopicPartitionsMapping` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND ProducerId = $SourceId AND Partition = $Partition;
2025-11-05T13:42:38.668235Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236295230468318:2460] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:38.668238Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 2 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:38.668481Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:42:38.668493Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236295230468321:2460], now have 1 active actors on pipe
2025-11-05T13:42:38.668559Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.668566Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.668595Z node 2 :PERSQUEUE INFO: new Cookie src|39729a13-e22000b3-846c9714-60d8ed5f_0 generated for partition 0 topic 'topic_A' owner src
2025-11-05T13:42:38.668604Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.668608Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.668618Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.668630Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:38.668645Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.668735Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.668739Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.668753Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.668768Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 2 partition: 0 MaxSeqNo: 0 sessionId: src|39729a13-e22000b3-846c9714-60d8ed5f_0
2025-11-05T13:42:38.672233Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350158672 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:38.672276Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|39729a13-e22000b3-846c9714-60d8ed5f_0" topic: "topic_A"
2025-11-05T13:42:38.672396Z :INFO: [/Root] MessageGroupId [src] SessionId [src|39729a13-e22000b3-846c9714-60d8ed5f_0] Write session: close. Timeout = 0 ms
2025-11-05T13:42:38.672401Z :INFO: [/Root] MessageGroupId [src] SessionId [src|39729a13-e22000b3-846c9714-60d8ed5f_0] Write session will now close
2025-11-05T13:42:38.672408Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|39729a13-e22000b3-846c9714-60d8ed5f_0] Write session: aborting
2025-11-05T13:42:38.672530Z :INFO: [/Root] MessageGroupId [src] SessionId [src|39729a13-e22000b3-846c9714-60d8ed5f_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:38.672536Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|39729a13-e22000b3-846c9714-60d8ed5f_0] Write session: destroy
2025-11-05T13:42:38.672726Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId: src|39729a13-e22000b3-846c9714-60d8ed5f_0 grpc read done: success: 0 data: 
2025-11-05T13:42:38.672732Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|39729a13-e22000b3-846c9714-60d8ed5f_0 grpc read failed
2025-11-05T13:42:38.672738Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|39729a13-e22000b3-846c9714-60d8ed5f_0 grpc closed
2025-11-05T13:42:38.672741Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|39729a13-e22000b3-846c9714-60d8ed5f_0 is DEAD
2025-11-05T13:42:38.672924Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:38.674119Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236295230468321:2460] destroyed
2025-11-05T13:42:38.674128Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:38.674135Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.674138Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.681593Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0] Write session: try to update token
2025-11-05T13:42:38.681782Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-11-05T13:42:38.681794Z :TRACE: [/Root] TRACE_EVENT DescribePartitionRequest  path=/Root/topic_A partition_id=0
2025-11-05T13:42:38.681837Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-11-05T13:42:38.682523Z node 2 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:42:38.682564Z node 2 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request path: "/Root/topic_A"
include_location: true
2025-11-05T13:42:38.682580Z node 2 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[2:7569236295230468330:2466]: Bootstrap
2025-11-05T13:42:38.683063Z node 2 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [2:7569236295230468330:2466]: Request location
2025-11-05T13:42:38.683134Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [2:7569236295230468339:2467] connected; active server actors: 1
2025-11-05T13:42:38.683147Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] addPartitionToResponse tabletId 72075186224037894, partitionId 0, NodeId 2, Generation 1
2025-11-05T13:42:38.683152Z node 2 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [2:7569236295230468330:2466]: Got location
2025-11-05T13:42:38.683242Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [2:7569236295230468339:2467] disconnected; active server actors: 1
2025-11-05T13:42:38.683246Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [2:7569236295230468339:2467] disconnected no session
2025-11-05T13:42:38.685590Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 2
    generation: 1
  }
}
2025-11-05T13:42:38.685621Z :TRACE: [/Root] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=2 pl_generation=1
2025-11-05T13:42:38.685630Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 2 exists in the endpoint pool.
2025-11-05T13:42:38.685639Z :TRACE: [/Root] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=2 Generation=1
2025-11-05T13:42:38.685643Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 2
2025-11-05T13:42:38.686170Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:38.686186Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 3
2025-11-05T13:42:38.689562Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-11-05T13:42:38.689612Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } }
2025-11-05T13:42:38.689618Z :TRACE: [/Root] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-11-05T13:42:38.689777Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:42:38.690036Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId:  grpc read done: success: 1 data: init_request { path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } }
2025-11-05T13:42:38.690121Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 3 path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } from ipv6:[::1]:49786
2025-11-05T13:42:38.690136Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=3 sessionId= userAgent="topic server" ip=ipv6:[::1]:49786 proto=topic  topic=topic_A durationSec=0
2025-11-05T13:42:38.690143Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:38.690156Z node 2 :PQ_WRITE_PROXY INFO: session to partition: 0, generation: 1
2025-11-05T13:42:38.690514Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId:  describe result for acl check
2025-11-05T13:42:38.690571Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint64; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `//Root/.metadata/TopicPartitionsMapping` WHERE Hash == $Hash AND Topic == $Topic AND ProducerId == $SourceId;
2025-11-05T13:42:38.690588Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64; DECLARE $SeqNo AS Uint64;
UPSERT INTO `//Root/.metadata/TopicPartitionsMapping` (Hash, Topic, ProducerId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-11-05T13:42:38.690589Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `//Root/.metadata/TopicPartitionsMapping` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND ProducerId = $SourceId AND Partition = $Partition;
2025-11-05T13:42:38.690597Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236295230468344:2469] (SourceId=test-message_group_id, PreferedPartition=0) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:38.690602Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 3 sessionId:  partition: 0 expectedGeneration: 1
2025-11-05T13:42:38.690842Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:42:38.690861Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236295230468347:2469], now have 1 active actors on pipe
2025-11-05T13:42:38.690871Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.690883Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.690916Z node 2 :PERSQUEUE INFO: new Cookie test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0 generated for partition 0 topic 'topic_A' owner test-message_group_id
2025-11-05T13:42:38.690932Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.690942Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.690953Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.690965Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:38.690992Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.691885Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.691900Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.691929Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.691954Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 3 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0
2025-11-05T13:42:38.692599Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:38.692612Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350158692 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:38.692631Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0"
2025-11-05T13:42:38.692635Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0
2025-11-05T13:42:38.692690Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=1, txId=01k9a42mtpd8gb6an3f511b9wm, WriteCount=1, AckCount=0
2025-11-05T13:42:38.692709Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-11-05T13:42:38.692731Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:42:38.692735Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-11-05T13:42:38.692961Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:42:38.693056Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP for a WriteId. SessionId: ydb://session/3?node_id=2&id=ZTAwZDIwYzUtZmFiZTI3NzctOTQ5NGJkYi02OWZiNTIwMw== TxId: 01k9a42mtpd8gb6an3f511b9wm
2025-11-05T13:42:38.693907Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:42:38.693924Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236295230468350:2469], now have 1 active actors on pipe
2025-11-05T13:42:38.694001Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of the request to KQP for the WriteId. SessionId: ydb://session/3?node_id=2&id=ZTAwZDIwYzUtZmFiZTI3NzctOTQ5NGJkYi02OWZiNTIwMw== TxId: 01k9a42mtpd8gb6an3f511b9wm Status: SUCCESS
2025-11-05T13:42:38.694018Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) SessionId: ydb://session/3?node_id=2&id=ZTAwZDIwYzUtZmFiZTI3NzctOTQ5NGJkYi02OWZiNTIwMw== TxId: 01k9a42mtpd8gb6an3f511b9wm WriteId: {2, 281474976715673}
2025-11-05T13:42:38.694103Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.694112Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.694121Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] partition {0, {2, 281474976715673}, 100000} for WriteId {2, 281474976715673}
2025-11-05T13:42:38.694155Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvSubscribeLock for WriteId {2, 281474976715673}
2025-11-05T13:42:38.694182Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.694244Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 2 Status: STATUS_SUBSCRIBED
2025-11-05T13:42:38.694249Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {2, 281474976715673}, TxId (empty maybe), Status STATUS_UNSPECIFIED
2025-11-05T13:42:38.694252Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] subscribed WriteId {2, 281474976715673}
2025-11-05T13:42:38.694525Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.694643Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:42:38.694758Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:42:38.694822Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] bootstrapping {0, {2, 281474976715673}, 100000} [2:7569236295230468357:2471]
2025-11-05T13:42:38.695083Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:42:38.695242Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:42:38.695351Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:42:38.695397Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:42:38.695411Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataStep
2025-11-05T13:42:38.695413Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitEndWriteTimestampStep
2025-11-05T13:42:38.695416Z node 2 :PERSQUEUE INFO: [topic_A:{0, {2, 281474976715673}, 100000}:TInitEndWriteTimestampStep] Initializing EndWriteTimestamp skipped because already initialized.
2025-11-05T13:42:38.695418Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Initializing completed.
2025-11-05T13:42:38.695422Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] init complete for topic 'topic_A' partition {0, {2, 281474976715673}, 100000} generation 1 [2:7569236295230468357:2471]
2025-11-05T13:42:38.695429Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] SYNC INIT topic topic_A partitition {0, {2, 281474976715673}, 100000} so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:42:38.695443Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Process pending events. Count 0
2025-11-05T13:42:38.695446Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.695448Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.695527Z node 2 :PERSQUEUE INFO: new Cookie test-message_group_id|eaa72e2e-f08ab6e9-2cd9f3c9-b0b0c7cc_0 generated for partition {0, {2, 281474976715673}, 100000} topic 'topic_A' owner test-message_group_id
2025-11-05T13:42:38.695544Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.695548Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.695557Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.695565Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyOwnerOk. Partition: {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:38.695579Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.695595Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=2&id=ZTAwZDIwYzUtZmFiZTI3NzctOTQ5NGJkYi02OWZiNTIwMw== TxId: 01k9a42mtpd8gb6an3f511b9wm
2025-11-05T13:42:38.695722Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=2&id=ZTAwZDIwYzUtZmFiZTI3NzctOTQ5NGJkYi02OWZiNTIwMw== TxId: 01k9a42mtpd8gb6an3f511b9wm Status: SUCCESS
2025-11-05T13:42:38.695741Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.695743Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.695758Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.697404Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.697416Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.697462Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Reserve bytes in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:38.697489Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-11-05T13:42:38.697505Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:38.698011Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.698025Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.698039Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Write in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:38.698052Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 1 partNo : 0 messageNo: 1 size 16457 offset: -1
2025-11-05T13:42:38.698079Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.698085Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.698110Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 1 partNo 0
2025-11-05T13:42:38.698163Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 16546 count 1 nextOffset 1 batches 1
2025-11-05T13:42:38.698169Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.698220Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Add new write blob: topic 'topic_A' partition {0, {2, 281474976715673}, 100000} compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 D0000100000_00000000000000000000_00000_0000000001_00000| size 16536 WTime 1762350158697
2025-11-05T13:42:38.698474Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.698492Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 100000 offset 0 partNo 0 count 1 size 16536
2025-11-05T13:42:38.698815Z node 2 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 100000 offset 0 count 1 size 16536 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.698842Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 16479 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:38.698852Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 1 parts 0 size 16536
2025-11-05T13:42:38.698854Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:38.698863Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715673}, 100000}, SeqNo: 1, partNo: 0, Offset: 0 is stored on disk
2025-11-05T13:42:38.698882Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.698884Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.698892Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-11-05T13:42:38.698903Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:38.699321Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:38.699366Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 1 written_in_tx { } } write_statistics { persisting_time { } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-11-05T13:42:38.699377Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=01k9a42mtpd8gb6an3f511b9wm, WriteCount=1, AckCount=1
2025-11-05T13:42:38.699657Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-11-05T13:42:38.700481Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236295230468373:2865], now have 1 active actors on pipe
2025-11-05T13:42:38.700530Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236295230468370 RawX2: 4503608217307552 } TxId: 281474976715674 Data { Operations { PartitionId: 0 Path: "/Root/topic_A" SupportivePartition: 100000 } Op: Commit SendingShards: 72075186224037894 ReceivingShards: 72075186224037894 Immediate: true WriteId { NodeId: 2 KeyId: 281474976715673 } }
2025-11-05T13:42:38.700539Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] PartitionId {0, {2, 281474976715673}, 100000} for WriteId {2, 281474976715673}
2025-11-05T13:42:38.700545Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715674 has WriteId {2, 281474976715673}
2025-11-05T13:42:38.700549Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] immediate transaction
2025-11-05T13:42:38.700564Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Send TEvGetWriteInfoRequest for TxId (empty maybe)
2025-11-05T13:42:38.700569Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.700573Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] The Tx (empty maybe) is waiting for TEvGetWriteInfoResponse
2025-11-05T13:42:38.700575Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still preprocessing - waiting for something
2025-11-05T13:42:38.700581Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoRequest
2025-11-05T13:42:38.700627Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Send TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:42:38.700641Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:42:38.700644Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Received TEvGetWriteInfoResponse for TxId (empty maybe)
2025-11-05T13:42:38.700648Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.700657Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.700665Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::CommitWriteOperations TxId: (empty maybe)
2025-11-05T13:42:38.700674Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] t.WriteInfo->BodyKeys.size=0, t.WriteInfo->BlobsFromHead.size=1
2025-11-05T13:42:38.700680Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Head=Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0, NewHead=Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:42:38.700699Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 1 partNo 0
2025-11-05T13:42:38.700743Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 16546 count 1 nextOffset 1 batches 1
2025-11-05T13:42:38.700759Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] schedule TEvPersQueue::TEvProposeTransactionResult(COMPLETE), reason=
2025-11-05T13:42:38.700766Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.700833Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Add new write blob: topic 'topic_A' partition 0 compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 d0000000000_00000000000000000000_00000_0000000001_00000| size 16536 WTime 1762350158699
2025-11-05T13:42:38.700886Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.700901Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 0 partNo 0 count 1 size 16536
2025-11-05T13:42:38.701254Z node 2 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 0 count 1 size 16536 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.701288Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 0 offset 0 partno 0 count 1 parts 0 size 16536
2025-11-05T13:42:38.701297Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 16479
2025-11-05T13:42:38.701331Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:42:38.701343Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer send read request for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 1 rrg 0
2025-11-05T13:42:38.701347Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.701348Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.701365Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTransactionCompleted WriteId {2, 281474976715673}
2025-11-05T13:42:38.701369Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvPQ::TEvDeletePartition to partition {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:38.701391Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Handle TEvPQ::TEvDeletePartition
2025-11-05T13:42:38.701412Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] read cookie 0 Topic 'topic_A' partition 0 user test-consumer offset 0 count 1 size 1024000 endOffset 1 max time lag 0ms effective offset 0
2025-11-05T13:42:38.701423Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] read cookie 0 added 0 blobs, size 0 count 0 last offset 0, current partition end offset: 1
2025-11-05T13:42:38.701443Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Reading cookie 0. All data is from uncompacted head.
2025-11-05T13:42:38.701448Z node 2 :PERSQUEUE DEBUG: FormAnswer for 0 blobs
2025-11-05T13:42:38.701464Z node 2 :PERSQUEUE DEBUG: Topic 'topic_A' partition 0 user test-consumer readTimeStamp done, result 1762350158697 queuesize 0 startOffset 0
2025-11-05T13:42:38.701470Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.701473Z node 2 :PERSQUEUE DEBUG: CacheProxy. Delete blobs from D0000100000(+) to D0000100001(-)
2025-11-05T13:42:38.701665Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 2 Status: STATUS_NOT_FOUND
2025-11-05T13:42:38.701685Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {2, 281474976715673}, TxId 281474976715674, Status STATUS_SUBSCRIBED
2025-11-05T13:42:38.701691Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] there is already a transaction TxId 281474976715674 for WriteId {2, 281474976715673}
2025-11-05T13:42:38.701815Z node 2 :PERSQUEUE DEBUG: Deleting head blob in L1. Partition 100000 offset 0 count 1 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.701856Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.701858Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.701945Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvDeletePartitionDone {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:38.701949Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] DeletePartition {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:38.701956Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvUnsubscribeLock for WriteId {2, 281474976715673}
2025-11-05T13:42:38.701960Z node 2 :PQ_TX WARN: [PQ: 72075186224037894] Unknown transaction 281474976715674
2025-11-05T13:42:38.701974Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.702042Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 1 parts 0
2025-11-05T13:42:38.702119Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.704372Z node 2 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:42:38.704891Z node 2 :TX_PROXY ERROR: Actor# [2:7569236295230468392:2872] txid# 281474976715675, issues: { message: "Check failed: path: \'/Root/topic_A\', error: path exist, request accepts it (id: [OwnerId: 72057594046644480, LocalPathId: 10], type: EPathTypePersQueueGroup, state: EPathStateNoChanges), source_location: ydb/core/tx/schemeshard/schemeshard__operation_create_pq.cpp:345" severity: 1 }
2025-11-05T13:42:38.705226Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:42:38.705385Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:42:38.705390Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:18634
2025-11-05T13:42:38.706139Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:42:38.706220Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:38.706230Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 4
2025-11-05T13:42:38.706311Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:42:38.706331Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 4 topic: "topic_A" message_group_id: "src" from ipv6:[::1]:49786
2025-11-05T13:42:38.706334Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=4 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:49786 proto=v1  topic=topic_A durationSec=0
2025-11-05T13:42:38.706337Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:38.706545Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId:  describe result for acl check
2025-11-05T13:42:38.706573Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint64; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `//Root/.metadata/TopicPartitionsMapping` WHERE Hash == $Hash AND Topic == $Topic AND ProducerId == $SourceId;
2025-11-05T13:42:38.706577Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64; DECLARE $SeqNo AS Uint64;
UPSERT INTO `//Root/.metadata/TopicPartitionsMapping` (Hash, Topic, ProducerId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-11-05T13:42:38.706578Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `//Root/.metadata/TopicPartitionsMapping` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND ProducerId = $SourceId AND Partition = $Partition;
2025-11-05T13:42:38.706598Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236295230468403:2482] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:38.706606Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 4 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:38.706708Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:42:38.706729Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236295230468406:2482], now have 1 active actors on pipe
2025-11-05T13:42:38.706737Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.706742Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.706774Z node 2 :PERSQUEUE INFO: new Cookie src|36076636-692d232d-b29199a9-bf9073fa_0 generated for partition 0 topic 'topic_A' owner src
2025-11-05T13:42:38.706787Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.706790Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.706800Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.706814Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:38.706836Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.706868Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.706875Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.706890Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.706902Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 4 partition: 0 MaxSeqNo: 0 sessionId: src|36076636-692d232d-b29199a9-bf9073fa_0
2025-11-05T13:42:38.707059Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350158707 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:38.707080Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|36076636-692d232d-b29199a9-bf9073fa_0" topic: "topic_A"
2025-11-05T13:42:38.707154Z :INFO: [/Root] MessageGroupId [src] SessionId [src|36076636-692d232d-b29199a9-bf9073fa_0] Write session: close. Timeout = 0 ms
2025-11-05T13:42:38.707160Z :INFO: [/Root] MessageGroupId [src] SessionId [src|36076636-692d232d-b29199a9-bf9073fa_0] Write session will now close
2025-11-05T13:42:38.707164Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|36076636-692d232d-b29199a9-bf9073fa_0] Write session: aborting
2025-11-05T13:42:38.707261Z :INFO: [/Root] MessageGroupId [src] SessionId [src|36076636-692d232d-b29199a9-bf9073fa_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:38.707265Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|36076636-692d232d-b29199a9-bf9073fa_0] Write session: destroy
2025-11-05T13:42:38.707368Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: src|36076636-692d232d-b29199a9-bf9073fa_0 grpc read done: success: 0 data: 
2025-11-05T13:42:38.707376Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: src|36076636-692d232d-b29199a9-bf9073fa_0 grpc read failed
2025-11-05T13:42:38.707381Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: src|36076636-692d232d-b29199a9-bf9073fa_0 grpc closed
2025-11-05T13:42:38.707383Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: src|36076636-692d232d-b29199a9-bf9073fa_0 is DEAD
2025-11-05T13:42:38.707575Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:38.707623Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236295230468406:2482] destroyed
2025-11-05T13:42:38.707630Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:38.707635Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.707637Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.713185Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=2, txId=01k9a42mvmc7n5h2xatcr024sr, WriteCount=1, AckCount=0
2025-11-05T13:42:38.718068Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 2 to 2
2025-11-05T13:42:38.723502Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:42:38.723521Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 2
2025-11-05T13:42:38.727177Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.727202Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.729404Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=3, txId=01k9a42mvmc7n5h2xatcr024sr, WriteCount=2, AckCount=0
2025-11-05T13:42:38.729438Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 3 to 3
2025-11-05T13:42:38.729463Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:42:38.729468Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 3
2025-11-05T13:42:38.736327Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:42:38.737359Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP for a WriteId. SessionId: ydb://session/3?node_id=2&id=MTEzZjk2MC01NWRmODI4ZC1mNDg4MGU5YS05YmM2OGZjYw== TxId: 01k9a42mvmc7n5h2xatcr024sr
2025-11-05T13:42:38.737525Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:42:38.737559Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236295230468415:2469], now have 1 active actors on pipe
2025-11-05T13:42:38.737776Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of the request to KQP for the WriteId. SessionId: ydb://session/3?node_id=2&id=MTEzZjk2MC01NWRmODI4ZC1mNDg4MGU5YS05YmM2OGZjYw== TxId: 01k9a42mvmc7n5h2xatcr024sr Status: SUCCESS
2025-11-05T13:42:38.737784Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) SessionId: ydb://session/3?node_id=2&id=MTEzZjk2MC01NWRmODI4ZC1mNDg4MGU5YS05YmM2OGZjYw== TxId: 01k9a42mvmc7n5h2xatcr024sr WriteId: {2, 281474976715676}
2025-11-05T13:42:38.737808Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.737817Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.737824Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] partition {0, {2, 281474976715676}, 100001} for WriteId {2, 281474976715676}
2025-11-05T13:42:38.737852Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvSubscribeLock for WriteId {2, 281474976715676}
2025-11-05T13:42:38.737873Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.737899Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715676 LockNode: 2 Status: STATUS_SUBSCRIBED
2025-11-05T13:42:38.737905Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {2, 281474976715676}, TxId (empty maybe), Status STATUS_UNSPECIFIED
2025-11-05T13:42:38.737907Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] subscribed WriteId {2, 281474976715676}
2025-11-05T13:42:38.738123Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.738212Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715676}, 100001}:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:42:38.738288Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715676}, 100001}:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:42:38.738330Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateInit] bootstrapping {0, {2, 281474976715676}, 100001} [2:7569236295230468421:2487]
2025-11-05T13:42:38.738486Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715676}, 100001}:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:42:38.738578Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715676}, 100001}:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:42:38.738615Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715676}, 100001}:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:42:38.738650Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715676}, 100001}:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:42:38.738701Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715676}, 100001}:Initializer] Start initializing step TInitDataStep
2025-11-05T13:42:38.738707Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715676}, 100001}:Initializer] Start initializing step TInitEndWriteTimestampStep
2025-11-05T13:42:38.738709Z node 2 :PERSQUEUE INFO: [topic_A:{0, {2, 281474976715676}, 100001}:TInitEndWriteTimestampStep] Initializing EndWriteTimestamp skipped because already initialized.
2025-11-05T13:42:38.738711Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715676}, 100001}:Initializer] Initializing completed.
2025-11-05T13:42:38.738716Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateInit] init complete for topic 'topic_A' partition {0, {2, 281474976715676}, 100001} generation 1 [2:7569236295230468421:2487]
2025-11-05T13:42:38.738722Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateInit] SYNC INIT topic topic_A partitition {0, {2, 281474976715676}, 100001} so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:42:38.738729Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Process pending events. Count 0
2025-11-05T13:42:38.738732Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.738735Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.738769Z node 2 :PERSQUEUE INFO: new Cookie test-message_group_id|7262e1f6-f9a1559f-185202d0-fcfe6267_0 generated for partition {0, {2, 281474976715676}, 100001} topic 'topic_A' owner test-message_group_id
2025-11-05T13:42:38.738777Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.738780Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.738785Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.738791Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyOwnerOk. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.738806Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.738819Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=2&id=MTEzZjk2MC01NWRmODI4ZC1mNDg4MGU5YS05YmM2OGZjYw== TxId: 01k9a42mvmc7n5h2xatcr024sr
2025-11-05T13:42:38.738904Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=2&id=MTEzZjk2MC01NWRmODI4ZC1mNDg4MGU5YS05YmM2OGZjYw== TxId: 01k9a42mvmc7n5h2xatcr024sr Status: SUCCESS
2025-11-05T13:42:38.738950Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.738957Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.738978Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:38.739012Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.739016Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.739035Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Reserve bytes in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715676 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:38.739052Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 2
2025-11-05T13:42:38.739068Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:38.739101Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.739105Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.739113Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Write in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715676 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:38.739198Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 0 messageNo: 1 size: 511944
2025-11-05T13:42:38.739248Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:42:38.739270Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 1 messageNo: 1 size: 511944
2025-11-05T13:42:38.739317Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-11-05T13:42:38.739332Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 2 messageNo: 1 size: 511944
2025-11-05T13:42:38.739397Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 3 messageNo: 1 size: 511944
2025-11-05T13:42:38.739467Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 4 messageNo: 1 size: 511944
2025-11-05T13:42:38.739540Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 5 messageNo: 1 size: 511944
2025-11-05T13:42:38.739641Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 6 messageNo: 1 size: 511944
2025-11-05T13:42:38.739713Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 7 messageNo: 1 size: 511944
2025-11-05T13:42:38.740078Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 8 messageNo: 1 size: 511944
2025-11-05T13:42:38.740394Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 9 messageNo: 1 size: 511944
2025-11-05T13:42:38.740471Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 10 messageNo: 1 size: 511944
2025-11-05T13:42:38.740538Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 11 messageNo: 1 size: 511944
2025-11-05T13:42:38.740601Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 12 messageNo: 1 size: 511944
2025-11-05T13:42:38.740706Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client PART message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 13 messageNo: 1 size: 344802
2025-11-05T13:42:38.740713Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 13 messageNo: 1 size 344802 offset: -1
2025-11-05T13:42:38.740736Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.740743Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.740760Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Reserve bytes in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715676 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:38.740768Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.740779Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.740804Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 0
2025-11-05T13:42:38.740826Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 1
2025-11-05T13:42:38.740833Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 2
2025-11-05T13:42:38.740837Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 3
2025-11-05T13:42:38.740841Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 4
2025-11-05T13:42:38.740845Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 5
2025-11-05T13:42:38.740849Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 6
2025-11-05T13:42:38.740854Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 7
2025-11-05T13:42:38.740857Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 8
2025-11-05T13:42:38.740865Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 9
2025-11-05T13:42:38.740869Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 10
2025-11-05T13:42:38.740873Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 11
2025-11-05T13:42:38.740880Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 12
2025-11-05T13:42:38.740884Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 13
2025-11-05T13:42:38.742163Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob complete sourceId '\0test-message_group_id' seqNo 2 partNo 13 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 7001250 count 1 nextOffset 1 batches 14
2025-11-05T13:42:38.742186Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.742297Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Add new write blob: topic 'topic_A' partition {0, {2, 281474976715676}, 100001} compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 D0000100001_00000000000000000000_00000_0000000001_00013 size 7001240 WTime 1762350158741
2025-11-05T13:42:38.747977Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.747995Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 2  requestId: <none> cookie: 3
2025-11-05T13:42:38.748008Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 100001 offset 0 partNo 0 count 1 size 7001240
2025-11-05T13:42:38.748025Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:38.748094Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:42:38.748104Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:42:38.748150Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Write in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715676 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:38.748167Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 3 partNo : 0 messageNo: 3 size 16457 offset: -1
2025-11-05T13:42:38.748195Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Can't process txs
2025-11-05T13:42:38.748414Z node 2 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 100001 offset 0 count 1 size 7001240 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.748447Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 100001 offset 0 partno 0 count 1 parts 13 size 7001240
2025-11-05T13:42:38.748460Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 7000382 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:38.748478Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748493Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 0, Offset: 0 is stored on disk
2025-11-05T13:42:38.748507Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748516Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 1, Offset: 0 is stored on disk
2025-11-05T13:42:38.748524Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748529Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 2, Offset: 0 is stored on disk
2025-11-05T13:42:38.748535Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748541Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 3, Offset: 0 is stored on disk
2025-11-05T13:42:38.748547Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748552Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 4, Offset: 0 is stored on disk
2025-11-05T13:42:38.748558Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748562Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 5, Offset: 0 is stored on disk
2025-11-05T13:42:38.748565Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748570Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 6, Offset: 0 is stored on disk
2025-11-05T13:42:38.748574Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748578Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 7, Offset: 0 is stored on disk
2025-11-05T13:42:38.748587Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748596Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 8, Offset: 0 is stored on disk
2025-11-05T13:42:38.748599Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748604Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 9, Offset: 0 is stored on disk
2025-11-05T13:42:38.748610Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748615Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 10, Offset: 0 is stored on disk
2025-11-05T13:42:38.748621Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748627Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 11, Offset: 0 is stored on disk
2025-11-05T13:42:38.748633Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748639Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 12, Offset: 0 is stored on disk
2025-11-05T13:42:38.748645Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.748650Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 1  requestId: <none> cookie: 2
2025-11-05T13:42:38.748651Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 2, partNo: 13, Offset: 0 is stored on disk
2025-11-05T13:42:38.748657Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:38.748669Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.748680Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.748700Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 3 partNo 0
2025-11-05T13:42:38.748726Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {2, 281474976715676}, 100001} part blob complete sourceId '\0test-message_group_id' seqNo 3 partNo 0 FormedBlobsCount 0 NewHead: Offset 1 PartNo 0 PackedSize 16546 count 1 nextOffset 2 batches 1
2025-11-05T13:42:38.748734Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.748782Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Add new write blob: topic 'topic_A' partition {0, {2, 281474976715676}, 100001} compactOffset 1,1 HeadOffset 1 endOffset 1 curOffset 2 D0000100001_00000000000000000001_00000_0000000001_00000| size 16536 WTime 1762350158748
2025-11-05T13:42:38.748825Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.748839Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 100001 offset 1 partNo 0 count 1 size 16536
2025-11-05T13:42:38.748961Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:38.749006Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 2 written_in_tx { } } write_statistics { persisting_time { nanos: 7000000 } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-11-05T13:42:38.749016Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] OnAck: seqNo=2, txId=01k9a42mvmc7n5h2xatcr024sr, WriteCount=2, AckCount=1
2025-11-05T13:42:38.749021Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 2
2025-11-05T13:42:38.749018Z node 2 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 100001 offset 1 count 1 size 16536 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.749055Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 100001 offset 1 partno 0 count 1 parts 0 size 16536
2025-11-05T13:42:38.749201Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 16479 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:38.749218Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.749240Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 3  requestId: <none> cookie: 3
2025-11-05T13:42:38.749242Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {2, 281474976715676}, 100001}, SeqNo: 3, partNo: 0, Offset: 1 is stored on disk
2025-11-05T13:42:38.749255Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:38.749265Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.749272Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.750020Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:38.750044Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 3 written_in_tx { } } write_statistics { persisting_time { } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-11-05T13:42:38.750049Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] OnAck: seqNo=3, txId=01k9a42mvmc7n5h2xatcr024sr, WriteCount=2, AckCount=2
2025-11-05T13:42:38.750288Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 3
2025-11-05T13:42:38.750833Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236295230468436 RawX2: 4503608217307573 } TxId: 281474976715677 Data { Operations { PartitionId: 0 Path: "/Root/topic_A" SupportivePartition: 100001 } Op: Commit SendingShards: 72075186224037894 ReceivingShards: 72075186224037894 Immediate: true WriteId { NodeId: 2 KeyId: 281474976715676 } }
2025-11-05T13:42:38.750847Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] PartitionId {0, {2, 281474976715676}, 100001} for WriteId {2, 281474976715676}
2025-11-05T13:42:38.750854Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715677 has WriteId {2, 281474976715676}
2025-11-05T13:42:38.750858Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] immediate transaction
2025-11-05T13:42:38.750872Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Send TEvGetWriteInfoRequest for TxId (empty maybe)
2025-11-05T13:42:38.750881Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.750884Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] The Tx (empty maybe) is waiting for TEvGetWriteInfoResponse
2025-11-05T13:42:38.750886Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still preprocessing - waiting for something
2025-11-05T13:42:38.750891Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoRequest
2025-11-05T13:42:38.750911Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Send TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:42:38.750920Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:42:38.750923Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Received TEvGetWriteInfoResponse for TxId (empty maybe)
2025-11-05T13:42:38.750925Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.750931Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.750940Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::CommitWriteOperations TxId: (empty maybe)
2025-11-05T13:42:38.750947Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] t.WriteInfo->BodyKeys.size=1, t.WriteInfo->BlobsFromHead.size=1
2025-11-05T13:42:38.750956Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Head=Offset 0 PartNo 0 PackedSize 16536 count 1 nextOffset 1 batches 1, NewHead=Offset 1 PartNo 0 PackedSize 0 count 0 nextOffset 1 batches 0
2025-11-05T13:42:38.750960Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] add key D0000100001_00000000000000000000_00000_0000000001_00013
2025-11-05T13:42:38.750994Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] PartitionedBlob.GetFormedBlobs().size=1
2025-11-05T13:42:38.751005Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] writing blob: topic 'topic_A' partition 0 old key D0000100001_00000000000000000000_00000_0000000001_00013 new key d0000000000_00000000000000000001_00000_0000000001_00013 size 7001240 WTime 1762350158750
2025-11-05T13:42:38.751016Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 3 partNo 0
2025-11-05T13:42:38.751036Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 3 partNo 0 FormedBlobsCount 0 NewHead: Offset 2 PartNo 0 PackedSize 16546 count 1 nextOffset 3 batches 1
2025-11-05T13:42:38.751046Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] schedule TEvPersQueue::TEvProposeTransactionResult(COMPLETE), reason=
2025-11-05T13:42:38.751055Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.751097Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Add new write blob: topic 'topic_A' partition 0 compactOffset 2,1 HeadOffset 0 endOffset 1 curOffset 3 d0000000000_00000000000000000002_00000_0000000001_00000| size 16536 WTime 1762350158750
2025-11-05T13:42:38.751146Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.751156Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 0 partNo 0 count 1 size 16536
2025-11-05T13:42:38.751159Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 2 partNo 0 count 1 size 16536
2025-11-05T13:42:38.751162Z node 2 :PERSQUEUE DEBUG: CacheProxy. Rename blob from D0000100001_00000000000000000000_00000_0000000001_00013 to d0000000000_00000000000000000001_00000_0000000001_00013
2025-11-05T13:42:38.751389Z node 2 :PERSQUEUE DEBUG: Renaming head blob in L1. Old partition 100001 old offset 0 old count 1 new partition 0 new offset 1 new count 1 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.751399Z node 2 :PERSQUEUE DEBUG: Duplicate blob in L1. Partition 0 offset 0 count 1 size 16536 actorID [2:7569236295230468259:2451] is actual 1
2025-11-05T13:42:38.751404Z node 2 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 0 count 1 size 16536 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.751407Z node 2 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 2 count 1 size 16536 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.751438Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037894' partition 0 offset 0 partno 0 count 1 parts 0
2025-11-05T13:42:38.751448Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 7016861
2025-11-05T13:42:38.751451Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Renamed. old Tablet '72075186224037894' partition 100001 offset 0 partno 0 count 1 parts 13, new Tablet '72075186224037894' partition 0 offset 1 partno 0 count 1 parts 13
2025-11-05T13:42:38.751454Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 0 offset 0 partno 0 count 1 parts 0 size 16536
2025-11-05T13:42:38.751458Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 0 offset 2 partno 0 count 1 parts 0 size 16536
2025-11-05T13:42:38.751472Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.751474Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.751506Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTransactionCompleted WriteId {2, 281474976715676}
2025-11-05T13:42:38.751516Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvPQ::TEvDeletePartition to partition {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.751520Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.751523Z node 2 :PERSQUEUE DEBUG: CacheProxy. Delete blobs from d0000000000_00000000000000000000_00000_0000000001_00000|(+) to d0000000000_00000000000000000000_00000_0000000001_00000|(+)
2025-11-05T13:42:38.751568Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Handle TEvPQ::TEvDeletePartition
2025-11-05T13:42:38.751652Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:38.751661Z node 2 :PERSQUEUE DEBUG: CacheProxy. Delete blobs from D0000100001(+) to D0000100002(-)
2025-11-05T13:42:38.751689Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715676 LockNode: 2 Status: STATUS_NOT_FOUND
2025-11-05T13:42:38.751697Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {2, 281474976715676}, TxId 281474976715677, Status STATUS_SUBSCRIBED
2025-11-05T13:42:38.751700Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] there is already a transaction TxId 281474976715677 for WriteId {2, 281474976715676}
2025-11-05T13:42:38.751785Z node 2 :PERSQUEUE DEBUG: Deleting head blob in L1. Partition 0 offset 0 count 1 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.751798Z node 2 :PERSQUEUE DEBUG: Deleting head blob in L1. Partition 100001 offset 1 count 1 actorID [2:7569236295230468259:2451]
2025-11-05T13:42:38.751807Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:38.751810Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.751810Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037894' partition 0 offset 0 partno 0 count 1 parts 0
2025-11-05T13:42:38.751812Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.751816Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037894' partition 100001 offset 1 partno 0 count 1 parts 0
2025-11-05T13:42:38.751848Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.751857Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.751944Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvDeletePartitionDone {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.751952Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] DeletePartition {0, {2, 281474976715676}, 100001}
2025-11-05T13:42:38.751960Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvUnsubscribeLock for WriteId {2, 281474976715676}
2025-11-05T13:42:38.751964Z node 2 :PQ_TX WARN: [PQ: 72075186224037894] Unknown transaction 281474976715677
2025-11-05T13:42:38.751975Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:38.752335Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:38.757412Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.757435Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.775343Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: close. Timeout 0.000000s
2025-11-05T13:42:38.775351Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session will now close
2025-11-05T13:42:38.775360Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: aborting
2025-11-05T13:42:38.775585Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:38.775592Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0]  PartitionId [0]  Generation [1] Write session: destroy
2025-11-05T13:42:38.777689Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0 grpc read done: success: 0 data: 
2025-11-05T13:42:38.777704Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0 grpc read failed
2025-11-05T13:42:38.777715Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0 grpc closed
2025-11-05T13:42:38.777720Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|28bce730-a66aa67-be75d94-de1b5d9e_0 is DEAD
2025-11-05T13:42:38.778035Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:38.778051Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:38.778065Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:38.778127Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236295230468347:2469] destroyed
2025-11-05T13:42:38.778137Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236295230468415:2469] destroyed
2025-11-05T13:42:38.778140Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236295230468350:2469] destroyed
2025-11-05T13:42:38.778151Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:38.778158Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.778160Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.827561Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.827579Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:38.857752Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:38.857765Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
