2025-11-05T13:42:56.835894Z node 2 :METADATA_PROVIDER WARN: fline=table_exists.cpp:54;actor=TTableExistsActor;event=undelivered;self_id=[2:7569236371739091238:2074];send_to=[0:7307199536658146131:7762515];
2025-11-05T13:42:56.835911Z 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:56.839153Z node 2 :PQ_READ_PROXY DEBUG: Direct read cache: : Created
test_client.cpp: SetPath # /home/runner/.ya/build/build_root/4xc1/003f3f/r3tmp/tmpwiNKcz/pdisk_1.dat
2025-11-05T13:42:56.854758Z node 2 :IMPORT WARN: Table profiles were not loaded
TServer::EnableGrpc on GrpcPort 21260, node 2
2025-11-05T13:42:56.869971Z node 2 :NET_CLASSIFIER WARN: distributable config is empty, broken or outdated, will use file: /home/runner/.ya/build/build_root/4xc1/003f3f/r3tmp/yandexHrU1Zu.tmp
2025-11-05T13:42:56.869983Z node 2 :NET_CLASSIFIER WARN: will try to initialize from file: /home/runner/.ya/build/build_root/4xc1/003f3f/r3tmp/yandexHrU1Zu.tmp
2025-11-05T13:42:56.870039Z node 2 :NET_CLASSIFIER WARN: successfully initialized from file: /home/runner/.ya/build/build_root/4xc1/003f3f/r3tmp/yandexHrU1Zu.tmp
2025-11-05T13:42:56.870083Z node 2 :NET_CLASSIFIER ERROR: got bad distributable configuration
2025-11-05T13:42:56.878867Z INFO: TTestServer started on Port 26716 GrpcPort 21260
TClient is connected to server localhost:26716
PQClient connected to localhost:21260
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:56.942184Z node 2 :HIVE WARN: HIVE#72057594037968897 Node(2, (0,0,0,0)) VolatileState: Unknown -> Disconnected
2025-11-05T13:42:56.942221Z node 2 :HIVE WARN: HIVE#72057594037968897 Node(2, (0,0,0,0)) VolatileState: Disconnected -> Connecting
2025-11-05T13:42:56.942503Z 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
2025-11-05T13:42:56.943082Z node 2 :HIVE WARN: HIVE#72057594037968897 Node(2, (0,0,0,0)) VolatileState: Connecting -> Connected
waiting...
2025-11-05T13:42:56.944256Z node 2 :FLAT_TX_SCHEMESHARD WARN: NotifyTxCompletion, unknown transaction, txId: 281474976715657, at schemeshard: 72057594046644480
waiting...
2025-11-05T13:42:56.956496Z 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:57.197664Z node 2 :KQP_COMPILE_ACTOR ERROR: Compilation failed, self: [2:7569236376034059255: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:57.198051Z node 2 :KQP_SESSION WARN: SessionId: ydb://session/3?node_id=2&id=ZDM2M2ZlZWItM2M1ZGEwZjAtMjBiOTE4MjAtN2I0MGU1M2E=, ActorId: [2:7569236376034059252:2314], ActorState: ExecuteState, TraceId: 01k9a436x8766eaqk755sy7kd8, ReplyQueryCompileError, status SCHEME_ERROR remove tx with tx_id: 
2025-11-05T13:42:57.198195Z 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:57.199032Z 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:57.206699Z 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:57.230475Z 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:7569236376034059530:2561] 
2025-11-05T13:42:57.837922Z node 2 :TX_CONVEYOR ERROR: fline=service.h:53;problem=unexpected event for task executor;ev_type=NActors::TEvents::TEvWakeup;
2025-11-05T13:43:01.836120Z node 2 :METADATA_PROVIDER ERROR: fline=table_exists.cpp:59;actor=TTableExistsActor;event=timeout;self_id=[2:7569236371739091238:2074];send_to=[0:7307199536658146131:7762515];
2025-11-05T13:43:01.836160Z 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:43:02.362703Z :WriteToTopic_Demo_12 INFO: TTopicSdkTestSetup started
2025-11-05T13:43:02.367272Z node 2 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:43:02.370550Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:43:02.370572Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][] pipe [2:7569236397508896321:2736] connected; active server actors: 1
2025-11-05T13:43:02.370600Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:43:02.370609Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:43:02.370679Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:43:02.370725Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] BALANCER INIT DONE for test-topic: (0, 72075186224037892) 
2025-11-05T13:43:02.370748Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:43:02.370777Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72057594046644480, NodeId 2, Generation 2
2025-11-05T13:43:02.370791Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] doesn't have tx info
2025-11-05T13:43:02.370795Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:43:02.370797Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] no config, start with empty partitions and default config
2025-11-05T13:43:02.370799Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:43:02.370805Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:43:02.370810Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892] doesn't have tx writes info
2025-11-05T13:43:02.370841Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236397508896354:2422], now have 1 active actors on pipe
2025-11-05T13:43:02.370843Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72075186224037892, NodeId 2, Generation 1
2025-11-05T13:43:02.370846Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236397508896320:2735], now have 1 active actors on pipe
2025-11-05T13:43:02.371007Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236371739091531 RawX2: 8589936735 } 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:43:02.371031Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] Propose TxId 281474976715671, WriteId (empty maybe)
2025-11-05T13:43:02.371053Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state UNKNOWN
2025-11-05T13:43:02.371056Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State UNKNOWN
2025-11-05T13:43:02.371060Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:43:02.371063Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from UNKNOWN to PREPARING
2025-11-05T13:43:02.371071Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:43:02.371131Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PREPARED MinStep: 1762350182411 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: 7569236371739091531 RawX2: 8589936735 } Partitions { }
2025-11-05T13:43:02.371147Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.371264Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.371270Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARING
2025-11-05T13:43:02.371271Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARING
2025-11-05T13:43:02.371274Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARING to PREPARED
2025-11-05T13:43:02.371448Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037892 TxId: 281474976715671
2025-11-05T13:43:02.371662Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236397508896366:2762], now have 1 active actors on pipe
2025-11-05T13:43:02.371699Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715671 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350182418 MediatorID: 72057594046382081 TabletID: 72075186224037892
2025-11-05T13:43:02.371707Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARED
2025-11-05T13:43:02.371708Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARED
2025-11-05T13:43:02.371711Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARED to PLANNING
2025-11-05T13:43:02.371715Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] PlanStep 1762350182418, PlanTxId 281474976715671
2025-11-05T13:43:02.371719Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:43:02.371770Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PLANNED MinStep: 1762350182411 MaxStep: 18446744073709551615 Step: 1762350182418 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: 7569236371739091531 RawX2: 8589936735 } Partitions { }
2025-11-05T13:43:02.371790Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.371903Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.371915Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PLANNING
2025-11-05T13:43:02.371917Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PLANNING
2025-11-05T13:43:02.371919Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNING to PLANNED
2025-11-05T13:43:02.371921Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxQueue.size 1
2025-11-05T13:43:02.371924Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] New ExecStep 1762350182418, ExecTxId 281474976715671
2025-11-05T13:43:02.372087Z node 2 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:43:02.372095Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNED to CALCULATING
2025-11-05T13:43:02.372118Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:43:02.372154Z node 2 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:43:02.372206Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] bootstrapping 0 [2:7569236397508896373:2426]
2025-11-05T13:43:02.372404Z node 2 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Initializing completed.
2025-11-05T13:43:02.372413Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] init complete for topic 'test-topic' partition 0 generation 1 [2:7569236397508896373:2426]
2025-11-05T13:43:02.372418Z 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:43:02.372566Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:43:02.372575Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.372595Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.372601Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:43:02.372603Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.372605Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.372606Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:43:02.372611Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350182418, TxId 281474976715671, Partition 0
2025-11-05T13:43:02.372612Z 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:43:02.372615Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] Handle TEvProposePartitionConfigResult
2025-11-05T13:43:02.372619Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] Partition responses 1/1
2025-11-05T13:43:02.372621Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATING
2025-11-05T13:43:02.372623Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATING
2025-11-05T13:43:02.372625Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATING FrontTxId 281474976715671
2025-11-05T13:43:02.372628Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:43:02.372631Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATING to CALCULATED
2025-11-05T13:43:02.372633Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:43:02.372701Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: CALCULATED MinStep: 1762350182411 MaxStep: 18446744073709551615 Step: 1762350182418 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: 7569236371739091531 RawX2: 8589936735 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:43:02.372723Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.372909Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.372915Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATED
2025-11-05T13:43:02.372916Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATED
2025-11-05T13:43:02.372917Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATED FrontTxId 281474976715671
2025-11-05T13:43:02.372919Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATED to WAIT_RS
2025-11-05T13:43:02.372927Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:43:02.372930Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveParticipantsDecision 1
2025-11-05T13:43:02.372936Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS to EXECUTING
2025-11-05T13:43:02.372938Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 0, Expected 1
2025-11-05T13:43:02.372953Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350182418, TxId 281474976715671
2025-11-05T13:43:02.372963Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.372966Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.373004Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.373041Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:02.373202Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] Handle TEvPQ::TEvTxCommitDone Step 1762350182418, TxId 281474976715671, Partition 0
2025-11-05T13:43:02.373207Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTING
2025-11-05T13:43:02.373208Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTING
2025-11-05T13:43:02.373210Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTING FrontTxId 281474976715671
2025-11-05T13:43:02.373211Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:43:02.373215Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId: 281474976715671 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:43:02.373215Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:43:02.373221Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] complete TxId 281474976715671
2025-11-05T13:43:02.373221Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.373222Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.373259Z 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:43:02.373278Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:43:02.373284Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] delete partitions for TxId 281474976715671
2025-11-05T13:43:02.373286Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTING to EXECUTED
2025-11-05T13:43:02.373288Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:43:02.373327Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: EXECUTED MinStep: 1762350182411 MaxStep: 18446744073709551615 Step: 1762350182418 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: 7569236371739091531 RawX2: 8589936735 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:43:02.373351Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.373767Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.373776Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTED
2025-11-05T13:43:02.373778Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTED
2025-11-05T13:43:02.373780Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTED FrontTxId 281474976715671
2025-11-05T13:43:02.373782Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:43:02.373784Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:43:02.373786Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:43:02.373789Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:43:02.373790Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:43:02.373792Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] add an TxId 281474976715671 to the list for deletion
2025-11-05T13:43:02.373795Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:43:02.373798Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] delete key for TxId 281474976715671
2025-11-05T13:43:02.373804Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.373832Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:43:02.373924Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:43:02.374033Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.374041Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state DELETING
2025-11-05T13:43:02.374043Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State DELETING
2025-11-05T13:43:02.374045Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] delete TxId 281474976715671
2025-11-05T13:43:02.374479Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:43:02.374721Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:43:02.374727Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:21260
2025-11-05T13:43:02.375878Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "test-topic" message_group_id: "src" }
2025-11-05T13:43:02.376064Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:43:02.376076Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 1
2025-11-05T13:43:02.376172Z 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:43:02.376193Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 1 topic: "test-topic" message_group_id: "src" from ipv6:[::1]:55308
2025-11-05T13:43:02.376204Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=1 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:55308 proto=v1  topic=test-topic durationSec=0
2025-11-05T13:43:02.376208Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:02.376702Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId:  describe result for acl check
2025-11-05T13:43:02.376739Z 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:43:02.376744Z 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:43:02.376746Z 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:43:02.376760Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236397508896417:2434] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:43:02.376768Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 1 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:43:02.376871Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 2, Generation: 1
2025-11-05T13:43:02.376880Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236397508896420:2434], now have 1 active actors on pipe
2025-11-05T13:43:02.376887Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:43:02.376892Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:43:02.376925Z node 2 :PERSQUEUE INFO: new Cookie src|4f45fff-88b01707-68176095-397126a6_0 generated for partition 0 topic 'test-topic' owner src
2025-11-05T13:43:02.376933Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.376943Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.376951Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.376964Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:43:02.376984Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.377013Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:43:02.377025Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:43:02.377045Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.377060Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 1 partition: 0 MaxSeqNo: 0 sessionId: src|4f45fff-88b01707-68176095-397126a6_0
2025-11-05T13:43:02.378805Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350182378 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:43:02.378870Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|4f45fff-88b01707-68176095-397126a6_0" topic: "test-topic"
2025-11-05T13:43:02.379126Z :INFO: [/Root] MessageGroupId [src] SessionId [src|4f45fff-88b01707-68176095-397126a6_0] Write session: close. Timeout = 0 ms
2025-11-05T13:43:02.379136Z :INFO: [/Root] MessageGroupId [src] SessionId [src|4f45fff-88b01707-68176095-397126a6_0] Write session will now close
2025-11-05T13:43:02.379146Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|4f45fff-88b01707-68176095-397126a6_0] Write session: aborting
2025-11-05T13:43:02.379269Z :INFO: [/Root] MessageGroupId [src] SessionId [src|4f45fff-88b01707-68176095-397126a6_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:43:02.379275Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|4f45fff-88b01707-68176095-397126a6_0] Write session: destroy
2025-11-05T13:43:02.379463Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId: src|4f45fff-88b01707-68176095-397126a6_0 grpc read done: success: 0 data: 
2025-11-05T13:43:02.379475Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|4f45fff-88b01707-68176095-397126a6_0 grpc read failed
2025-11-05T13:43:02.379482Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|4f45fff-88b01707-68176095-397126a6_0 grpc closed
2025-11-05T13:43:02.379484Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|4f45fff-88b01707-68176095-397126a6_0 is DEAD
2025-11-05T13:43:02.379714Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:43:02.379760Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [2:7569236397508896420:2434] destroyed
2025-11-05T13:43:02.379769Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:43:02.379774Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.379776Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.380097Z :WriteToTopic_Demo_12 INFO: Topic created
2025-11-05T13:43:02.385151Z node 2 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:43:02.386482Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:43:02.386568Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:43:02.388529Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][] pipe [2:7569236397508896467:2807] connected; active server actors: 1
2025-11-05T13:43:02.388553Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:43:02.388641Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:43:02.388666Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:43:02.388700Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:43:02.388739Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] doesn't have tx info
2025-11-05T13:43:02.388748Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:43:02.388750Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] no config, start with empty partitions and default config
2025-11-05T13:43:02.388754Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:43:02.388756Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:43:02.388758Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:43:02.388769Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894] doesn't have tx writes info
2025-11-05T13:43:02.388772Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] BALANCER INIT DONE for topic_A: (0, 72075186224037894) 
2025-11-05T13:43:02.388788Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896466:2806], now have 1 active actors on pipe
2025-11-05T13:43:02.388846Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientConnected TabletId 72075186224037894, NodeId 2, Generation 1
2025-11-05T13:43:02.388853Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientConnected TabletId 72057594046644480, NodeId 2, Generation 2
2025-11-05T13:43:02.388972Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236371739091531 RawX2: 8589936735 } 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:43:02.389015Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Propose TxId 281474976715672, WriteId (empty maybe)
2025-11-05T13:43:02.389022Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state UNKNOWN
2025-11-05T13:43:02.389024Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State UNKNOWN
2025-11-05T13:43:02.389028Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:43:02.389031Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from UNKNOWN to PREPARING
2025-11-05T13:43:02.389037Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:43:02.389084Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PREPARED MinStep: 1762350182425 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: 7569236371739091531 RawX2: 8589936735 } Partitions { }
2025-11-05T13:43:02.389104Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.389112Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896497:2448], now have 1 active actors on pipe
2025-11-05T13:43:02.389251Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.389258Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARING
2025-11-05T13:43:02.389259Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARING
2025-11-05T13:43:02.389261Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARING to PREPARED
2025-11-05T13:43:02.389633Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037894 TxId: 281474976715672
2025-11-05T13:43:02.389648Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896508:2831], now have 1 active actors on pipe
2025-11-05T13:43:02.389665Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715672 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350182439 MediatorID: 72057594046382081 TabletID: 72075186224037894
2025-11-05T13:43:02.389671Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARED
2025-11-05T13:43:02.389673Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARED
2025-11-05T13:43:02.389675Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARED to PLANNING
2025-11-05T13:43:02.389679Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] PlanStep 1762350182439, PlanTxId 281474976715672
2025-11-05T13:43:02.389683Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:43:02.389750Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PLANNED MinStep: 1762350182425 MaxStep: 18446744073709551615 Step: 1762350182439 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: 7569236371739091531 RawX2: 8589936735 } Partitions { }
2025-11-05T13:43:02.389767Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.389905Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.389913Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PLANNING
2025-11-05T13:43:02.389917Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PLANNING
2025-11-05T13:43:02.389919Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNING to PLANNED
2025-11-05T13:43:02.389922Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxQueue.size 1
2025-11-05T13:43:02.389927Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] New ExecStep 1762350182439, ExecTxId 281474976715672
2025-11-05T13:43:02.390084Z node 2 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:43:02.390093Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNED to CALCULATING
2025-11-05T13:43:02.390099Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:43:02.390130Z node 2 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:43:02.390183Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] bootstrapping 0 [2:7569236397508896515:2452]
2025-11-05T13:43:02.390417Z node 2 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Initializing completed.
2025-11-05T13:43:02.390425Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] init complete for topic 'topic_A' partition 0 generation 1 [2:7569236397508896515:2452]
2025-11-05T13:43:02.390431Z 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:43:02.390539Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:43:02.390548Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.390561Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.390569Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:43:02.390571Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.390573Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.390575Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:43:02.390581Z 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:43:02.390616Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350182439, TxId 281474976715672, Partition 0
2025-11-05T13:43:02.390631Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] Handle TEvProposePartitionConfigResult
2025-11-05T13:43:02.390637Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] Partition responses 1/1
2025-11-05T13:43:02.390639Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATING
2025-11-05T13:43:02.390641Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATING
2025-11-05T13:43:02.390644Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATING FrontTxId 281474976715672
2025-11-05T13:43:02.390648Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:43:02.390650Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATING to CALCULATED
2025-11-05T13:43:02.390658Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:43:02.390724Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: CALCULATED MinStep: 1762350182425 MaxStep: 18446744073709551615 Step: 1762350182439 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: 7569236371739091531 RawX2: 8589936735 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:43:02.390743Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.390954Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.390960Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATED
2025-11-05T13:43:02.390962Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATED
2025-11-05T13:43:02.390963Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATED FrontTxId 281474976715672
2025-11-05T13:43:02.390965Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATED to WAIT_RS
2025-11-05T13:43:02.390972Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:43:02.390975Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveParticipantsDecision 1
2025-11-05T13:43:02.390980Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS to EXECUTING
2025-11-05T13:43:02.390982Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 0, Expected 1
2025-11-05T13:43:02.390995Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350182439, TxId 281474976715672
2025-11-05T13:43:02.391002Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.391004Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.391022Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.391049Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:02.391354Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:43:02.391363Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.391365Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.391380Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTxCommitDone Step 1762350182439, TxId 281474976715672, Partition 0
2025-11-05T13:43:02.391382Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTING
2025-11-05T13:43:02.391383Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTING
2025-11-05T13:43:02.391384Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTING FrontTxId 281474976715672
2025-11-05T13:43:02.391386Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:43:02.391389Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId: 281474976715672 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:43:02.391396Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] complete TxId 281474976715672
2025-11-05T13:43:02.391439Z 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:43:02.391451Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:43:02.391456Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] delete partitions for TxId 281474976715672
2025-11-05T13:43:02.391461Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTING to EXECUTED
2025-11-05T13:43:02.391464Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:43:02.391505Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: EXECUTED MinStep: 1762350182425 MaxStep: 18446744073709551615 Step: 1762350182439 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: 7569236371739091531 RawX2: 8589936735 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:43:02.391545Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.391635Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.391641Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTED
2025-11-05T13:43:02.391642Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTED
2025-11-05T13:43:02.391644Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTED FrontTxId 281474976715672
2025-11-05T13:43:02.391646Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:43:02.391647Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:43:02.391650Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:43:02.391652Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:43:02.391653Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:43:02.391655Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] add an TxId 281474976715672 to the list for deletion
2025-11-05T13:43:02.391656Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:43:02.391659Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] delete key for TxId 281474976715672
2025-11-05T13:43:02.391663Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.391909Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:43:02.391929Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:43:02.391953Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:43:02.391977Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.391982Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state DELETING
2025-11-05T13:43:02.391983Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State DELETING
2025-11-05T13:43:02.391985Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] delete TxId 281474976715672
2025-11-05T13:43:02.392258Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:43:02.392489Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:43:02.392759Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:43:02.392766Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:21260
2025-11-05T13:43:02.394023Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:43:02.394166Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:43:02.394177Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 2
2025-11-05T13:43:02.394278Z 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:43:02.394296Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 2 topic: "topic_A" message_group_id: "src" from ipv6:[::1]:55308
2025-11-05T13:43:02.394300Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=2 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:55308 proto=v1  topic=topic_A durationSec=0
2025-11-05T13:43:02.394304Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:02.394701Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId:  describe result for acl check
2025-11-05T13:43:02.394734Z 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:43:02.394739Z 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:43:02.394741Z 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:43:02.394753Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236397508896550:2460] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:43:02.394756Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 2 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:43:02.394856Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:43:02.394869Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896553:2460], now have 1 active actors on pipe
2025-11-05T13:43:02.394879Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.394883Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.394908Z node 2 :PERSQUEUE INFO: new Cookie src|76973b5b-3827c8d3-b7b884b4-99689128_0 generated for partition 0 topic 'topic_A' owner src
2025-11-05T13:43:02.394919Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.394926Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.394935Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.394949Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:43:02.394977Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.395007Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.395013Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.395022Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.395043Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 2 partition: 0 MaxSeqNo: 0 sessionId: src|76973b5b-3827c8d3-b7b884b4-99689128_0
2025-11-05T13:43:02.395276Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350182395 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:43:02.395302Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|76973b5b-3827c8d3-b7b884b4-99689128_0" topic: "topic_A"
2025-11-05T13:43:02.395411Z :INFO: [/Root] MessageGroupId [src] SessionId [src|76973b5b-3827c8d3-b7b884b4-99689128_0] Write session: close. Timeout = 0 ms
2025-11-05T13:43:02.395421Z :INFO: [/Root] MessageGroupId [src] SessionId [src|76973b5b-3827c8d3-b7b884b4-99689128_0] Write session will now close
2025-11-05T13:43:02.395429Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|76973b5b-3827c8d3-b7b884b4-99689128_0] Write session: aborting
2025-11-05T13:43:02.395563Z :INFO: [/Root] MessageGroupId [src] SessionId [src|76973b5b-3827c8d3-b7b884b4-99689128_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:43:02.395568Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|76973b5b-3827c8d3-b7b884b4-99689128_0] Write session: destroy
2025-11-05T13:43:02.395712Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId: src|76973b5b-3827c8d3-b7b884b4-99689128_0 grpc read done: success: 0 data: 
2025-11-05T13:43:02.395720Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|76973b5b-3827c8d3-b7b884b4-99689128_0 grpc read failed
2025-11-05T13:43:02.395726Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|76973b5b-3827c8d3-b7b884b4-99689128_0 grpc closed
2025-11-05T13:43:02.395728Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|76973b5b-3827c8d3-b7b884b4-99689128_0 is DEAD
2025-11-05T13:43:02.395966Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:43:02.396019Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236397508896553:2460] destroyed
2025-11-05T13:43:02.396037Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:43:02.396050Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.396052Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.402627Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: try to update token
2025-11-05T13:43:02.402803Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Start write session. Will connect to nodeId: 0
2025-11-05T13:43:02.403037Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: write to message_group: test-message_group_id
2025-11-05T13:43:02.403119Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: send init request: init_request { path: "topic_A" producer_id: "test-message_group_id" message_group_id: "test-message_group_id" }
2025-11-05T13:43:02.403124Z :TRACE: [/Root] TRACE_EVENT InitRequest 
2025-11-05T13:43:02.403235Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:43:02.403241Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:43:02.403258Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 3
2025-11-05T13:43:02.403380Z 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" message_group_id: "test-message_group_id" }
2025-11-05T13:43:02.403418Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 3 path: "topic_A" producer_id: "test-message_group_id" message_group_id: "test-message_group_id" from ipv6:[::1]:55308
2025-11-05T13:43:02.403425Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=3 sessionId= userAgent="topic server" ip=ipv6:[::1]:55308 proto=topic  topic=topic_A durationSec=0
2025-11-05T13:43:02.403429Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:02.403665Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId:  describe result for acl check
2025-11-05T13:43:02.403705Z 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:43:02.403711Z 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:43:02.403713Z 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:43:02.403726Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236397508896564:2467] (SourceId=test-message_group_id, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:43:02.403736Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 3 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:43:02.403875Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:43:02.403882Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896567:2467], now have 1 active actors on pipe
2025-11-05T13:43:02.403890Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.403900Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.403929Z node 2 :PERSQUEUE INFO: new Cookie test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0 generated for partition 0 topic 'topic_A' owner test-message_group_id
2025-11-05T13:43:02.403942Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.403951Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.403961Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.403977Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:43:02.404004Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.404054Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.404066Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.404089Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.404108Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 3 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0
2025-11-05T13:43:02.404270Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:43:02.404281Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350182404 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:43:02.404294Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session established. Init response: session_id: "test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0"
2025-11-05T13:43:02.404296Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0
2025-11-05T13:43:02.404298Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  MessageGroupId [test-message_group_id] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:43:02.404349Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-11-05T13:43:02.404355Z :TRACE: [/Root] TRACE_EVENT DescribePartitionRequest  path=/Root/topic_A partition_id=0
2025-11-05T13:43:02.404388Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-11-05T13:43:02.404790Z node 2 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:43:02.404864Z node 2 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request path: "/Root/topic_A"
include_location: true
2025-11-05T13:43:02.404899Z node 2 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[2:7569236397508896570:2469]: Bootstrap
2025-11-05T13:43:02.405251Z node 2 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [2:7569236397508896570:2469]: Request location
2025-11-05T13:43:02.405329Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [2:7569236397508896579:2470] connected; active server actors: 1
2025-11-05T13:43:02.405346Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] addPartitionToResponse tabletId 72075186224037894, partitionId 0, NodeId 2, Generation 1
2025-11-05T13:43:02.405354Z node 2 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [2:7569236397508896570:2469]: Got location
2025-11-05T13:43:02.405382Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [2:7569236397508896579:2470] disconnected; active server actors: 1
2025-11-05T13:43:02.405394Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [2:7569236397508896579:2470] disconnected no session
2025-11-05T13:43:02.405661Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 2
    generation: 1
  }
}
2025-11-05T13:43:02.405670Z :TRACE: [/Root] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=2 pl_generation=1
2025-11-05T13:43:02.405676Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 2 exists in the endpoint pool.
2025-11-05T13:43:02.405682Z :TRACE: [/Root] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=2 Generation=1
2025-11-05T13:43:02.405686Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 2
2025-11-05T13:43:02.405905Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-11-05T13:43:02.406048Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-11-05T13:43:02.406026Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0 grpc read done: success: 0 data: 
2025-11-05T13:43:02.406036Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0 grpc read failed
2025-11-05T13:43:02.406044Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0 grpc closed
2025-11-05T13:43:02.406047Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0 is DEAD
2025-11-05T13:43:02.406076Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  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:43:02.406080Z :TRACE: [/Root] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-11-05T13:43:02.406104Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:43:02.406113Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 4
2025-11-05T13:43:02.406168Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:43:02.406224Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:43:02.406267Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236397508896567:2467] destroyed
2025-11-05T13:43:02.406280Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:43:02.406288Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 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:43:02.406299Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.406302Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.406306Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 4 path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } from ipv6:[::1]:55308
2025-11-05T13:43:02.406309Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=4 sessionId= userAgent="topic server" ip=ipv6:[::1]:55308 proto=topic  topic=topic_A durationSec=0
2025-11-05T13:43:02.406311Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:02.406316Z node 2 :PQ_WRITE_PROXY INFO: session to partition: 0, generation: 1
2025-11-05T13:43:02.406523Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId:  describe result for acl check
2025-11-05T13:43:02.406561Z 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:43:02.406566Z 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:43:02.406568Z 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:43:02.406574Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236397508896584:2472] (SourceId=test-message_group_id, PreferedPartition=0) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:43:02.406578Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 4 sessionId:  partition: 0 expectedGeneration: 1
2025-11-05T13:43:02.406677Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:43:02.406691Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896587:2472], now have 1 active actors on pipe
2025-11-05T13:43:02.406695Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.406700Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.406718Z node 2 :PERSQUEUE INFO: new Cookie test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0 generated for partition 0 topic 'topic_A' owner test-message_group_id
2025-11-05T13:43:02.406727Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.406730Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.406739Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.406750Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:43:02.406772Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.406804Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.406810Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.406830Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.406847Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 4 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0
2025-11-05T13:43:02.407025Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:43:02.407040Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|7fe91e3b-7684bbb8-de04dc5d-be8478ba_0]  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0"
2025-11-05T13:43:02.407044Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0
2025-11-05T13:43:02.407048Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:43:02.407093Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=1, txId=01k9a43c01cn9cd7ggspg9xp2j, WriteCount=1, AckCount=0
2025-11-05T13:43:02.407105Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-11-05T13:43:02.407123Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:02.407136Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-11-05T13:43:02.407285Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:43:02.407346Z 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=YzIyY2YwODMtZTA5OTdjNGQtODBhZjg1MjAtMzYzMmRiNWU= TxId: 01k9a43c01cn9cd7ggspg9xp2j
2025-11-05T13:43:02.407413Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:43:02.407423Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896590:2472], now have 1 active actors on pipe
2025-11-05T13:43:02.407641Z 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=YzIyY2YwODMtZTA5OTdjNGQtODBhZjg1MjAtMzYzMmRiNWU= TxId: 01k9a43c01cn9cd7ggspg9xp2j Status: SUCCESS
2025-11-05T13:43:02.407649Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) SessionId: ydb://session/3?node_id=2&id=YzIyY2YwODMtZTA5OTdjNGQtODBhZjg1MjAtMzYzMmRiNWU= TxId: 01k9a43c01cn9cd7ggspg9xp2j WriteId: {2, 281474976715673}
2025-11-05T13:43:02.407660Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.407664Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.407669Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] partition {0, {2, 281474976715673}, 100000} for WriteId {2, 281474976715673}
2025-11-05T13:43:02.407699Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvSubscribeLock for WriteId {2, 281474976715673}
2025-11-05T13:43:02.407729Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.407754Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 2 Status: STATUS_SUBSCRIBED
2025-11-05T13:43:02.407762Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {2, 281474976715673}, TxId (empty maybe), Status STATUS_UNSPECIFIED
2025-11-05T13:43:02.407764Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] subscribed WriteId {2, 281474976715673}
2025-11-05T13:43:02.407993Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.408159Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:43:02.408221Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:43:02.408298Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] bootstrapping {0, {2, 281474976715673}, 100000} [2:7569236397508896596:2474]
2025-11-05T13:43:02.408501Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:43:02.408591Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:43:02.408616Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:43:02.408697Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:43:02.408717Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataStep
2025-11-05T13:43:02.408722Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitEndWriteTimestampStep
2025-11-05T13:43:02.408725Z node 2 :PERSQUEUE INFO: [topic_A:{0, {2, 281474976715673}, 100000}:TInitEndWriteTimestampStep] Initializing EndWriteTimestamp skipped because already initialized.
2025-11-05T13:43:02.408726Z node 2 :PERSQUEUE DEBUG: [topic_A:{0, {2, 281474976715673}, 100000}:Initializer] Initializing completed.
2025-11-05T13:43:02.408730Z 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:7569236397508896596:2474]
2025-11-05T13:43:02.408735Z 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:43:02.408740Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Process pending events. Count 0
2025-11-05T13:43:02.408742Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.408743Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.408780Z node 2 :PERSQUEUE INFO: new Cookie test-message_group_id|8c2ee576-8574500f-7f48c93e-363299ae_0 generated for partition {0, {2, 281474976715673}, 100000} topic 'topic_A' owner test-message_group_id
2025-11-05T13:43:02.408789Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.408792Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.408798Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.408808Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyOwnerOk. Partition: {0, {2, 281474976715673}, 100000}
2025-11-05T13:43:02.408829Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.408850Z 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=YzIyY2YwODMtZTA5OTdjNGQtODBhZjg1MjAtMzYzMmRiNWU= TxId: 01k9a43c01cn9cd7ggspg9xp2j
2025-11-05T13:43:02.408943Z 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=YzIyY2YwODMtZTA5OTdjNGQtODBhZjg1MjAtMzYzMmRiNWU= TxId: 01k9a43c01cn9cd7ggspg9xp2j Status: SUCCESS
2025-11-05T13:43:02.408961Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.408963Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.408981Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:02.409011Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.409016Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.409048Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Reserve bytes in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:43:02.409067Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-11-05T13:43:02.409083Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:43:02.409105Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.409110Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.409117Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Write in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:43:02.409124Z 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 81 offset: -1
2025-11-05T13:43:02.409144Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.409153Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.409166Z 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:43:02.409212Z 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 170 count 1 nextOffset 1 batches 1
2025-11-05T13:43:02.409221Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.409257Z 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 158 WTime 1762350182409
2025-11-05T13:43:02.409287Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:02.409298Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 100000 offset 0 partNo 0 count 1 size 158
2025-11-05T13:43:02.409507Z node 2 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 100000 offset 0 count 1 size 158 actorID [2:7569236397508896491:2451]
2025-11-05T13:43:02.409534Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 103 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:43:02.409539Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 1 parts 0 size 158
2025-11-05T13:43:02.409557Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715673}, 100000}
2025-11-05T13:43:02.409572Z 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:43:02.409576Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-11-05T13:43:02.409588Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:43:02.409589Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.409591Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.409801Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:43:02.409852Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_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:43:02.409860Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=01k9a43c01cn9cd7ggspg9xp2j, WriteCount=1, AckCount=1
2025-11-05T13:43:02.409864Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-11-05T13:43:02.410158Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896608:2865], now have 1 active actors on pipe
2025-11-05T13:43:02.410313Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896611:2867], now have 1 active actors on pipe
2025-11-05T13:43:02.410337Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 2 Status: STATUS_NOT_FOUND
2025-11-05T13:43:02.410345Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {2, 281474976715673}, TxId (empty maybe), Status STATUS_SUBSCRIBED
2025-11-05T13:43:02.410348Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] delete partitions for WriteId {2, 281474976715673} (longTxService lost tx)
2025-11-05T13:43:02.410351Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvPQ::TEvDeletePartition to partition {0, {2, 281474976715673}, 100000}
2025-11-05T13:43:02.410364Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896612:2868], now have 1 active actors on pipe
2025-11-05T13:43:02.410384Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Handle TEvPQ::TEvDeletePartition
2025-11-05T13:43:02.410405Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:02.410412Z node 2 :PERSQUEUE DEBUG: CacheProxy. Delete blobs from D0000100000(+) to D0000100001(-)
2025-11-05T13:43:02.410524Z node 2 :PERSQUEUE DEBUG: Deleting head blob in L1. Partition 100000 offset 0 count 1 actorID [2:7569236397508896491:2451]
2025-11-05T13:43:02.410547Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 1 parts 0
2025-11-05T13:43:02.410557Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.410559Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.410570Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvDeletePartitionDone {0, {2, 281474976715673}, 100000}
2025-11-05T13:43:02.410577Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] DeletePartition {0, {2, 281474976715673}, 100000}
2025-11-05T13:43:02.410585Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvUnsubscribeLock for WriteId {2, 281474976715673}
2025-11-05T13:43:02.410598Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:02.410701Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:02.473038Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.473059Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.490468Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.490487Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.510688Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236397508896621:2874], now have 1 active actors on pipe
2025-11-05T13:43:02.510859Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=2, txId=01k9a43c01cn9cd7ggspg9xp2j, WriteCount=2, AckCount=1
2025-11-05T13:43:02.510869Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 2 to 2
2025-11-05T13:43:02.510886Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:02.510890Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 2
2025-11-05T13:43:02.511155Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:43:02.511275Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-11-05T13:43:02.511317Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:02.511328Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:02.511334Z node 2 :PERSQUEUE WARN: tablet 72075186224037894 topic 'topic_A error: lost messages
2025-11-05T13:43:02.511343Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvError Cookie 11, Error lost messages
2025-11-05T13:43:02.511347Z node 2 :PERSQUEUE ERROR: Answer error topic: 'topic_A' partition: 0 messageNo: 2 requestId: <none> error: lost messages
2025-11-05T13:43:02.511362Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:43:02.511391Z node 2 :PQ_WRITE_PROXY INFO: session v1 error cookie: 4 reason: status is not ok: lost messages sessionId: test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0
2025-11-05T13:43:02.511497Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0 is DEAD
2025-11-05T13:43:02.511531Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:43:02.511547Z :TRACE: [/Root] TRACE_EVENT Error  status=PRECONDITION_FAILED
2025-11-05T13:43:02.511551Z :TRACE: [/Root] TRACE_EVENT ClearDirectWriteToPartitionId 
2025-11-05T13:43:02.511565Z :ERROR: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  MessageGroupId [test-message_group_id] Got error. Status: PRECONDITION_FAILED, Description: <main>: Error: status is not ok: lost messages, code: 500031 
2025-11-05T13:43:02.511568Z :ERROR: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  MessageGroupId [test-message_group_id] Write session will not restart after a fatal error
2025-11-05T13:43:02.511571Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  MessageGroupId [test-message_group_id] Write session will now close
2025-11-05T13:43:02.511587Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  MessageGroupId [test-message_group_id] Write session: aborting
2025-11-05T13:43:02.511621Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:43:02.511684Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236397508896587:2472] destroyed
2025-11-05T13:43:02.511692Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236397508896590:2472] destroyed
2025-11-05T13:43:02.511703Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:43:02.511711Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.511720Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.511984Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|91f6081c-5b496815-9b57f8ac-fc44d2dc_0]  MessageGroupId [test-message_group_id] Write session: destroy
2025-11-05T13:43:02.573408Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.573437Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:02.590768Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:02.590785Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
