2025-11-05T13:43:59.674556Z node 12 :METADATA_PROVIDER WARN: fline=table_exists.cpp:54;actor=TTableExistsActor;event=undelivered;self_id=[12:7569236640668444735:2066];send_to=[0:7307199536658146131:7762515];
2025-11-05T13:43:59.674568Z node 12 :METADATA_PROVIDER ERROR: fline=accessor_snapshot_base.cpp:69;action=cannot detect path existence;path=//Root/.metadata/initialization/migrations;error=scheme_cache_undelivered_message;
test_client.cpp: SetPath # /home/runner/.ya/build/build_root/4xc1/003f58/r3tmp/tmphtKu6v/pdisk_1.dat
2025-11-05T13:43:59.677459Z node 12 :PQ_READ_PROXY DEBUG: Direct read cache: : Created
2025-11-05T13:43:59.688711Z node 12 :IMPORT WARN: Table profiles were not loaded
2025-11-05T13:43:59.688912Z node 12 :CONFIGS_DISPATCHER ERROR: Notification cookie mismatch for subscription [12:7569236640668444707:2081] 1762350239674363 != 1762350239674366
TServer::EnableGrpc on GrpcPort 28700, node 12
2025-11-05T13:43:59.694489Z node 12 :NET_CLASSIFIER WARN: distributable config is empty, broken or outdated, will use file: /home/runner/.ya/build/build_root/4xc1/003f58/r3tmp/yandexSe3IuC.tmp
2025-11-05T13:43:59.694504Z node 12 :NET_CLASSIFIER WARN: will try to initialize from file: /home/runner/.ya/build/build_root/4xc1/003f58/r3tmp/yandexSe3IuC.tmp
2025-11-05T13:43:59.694554Z node 12 :NET_CLASSIFIER WARN: successfully initialized from file: /home/runner/.ya/build/build_root/4xc1/003f58/r3tmp/yandexSe3IuC.tmp
2025-11-05T13:43:59.694601Z node 12 :NET_CLASSIFIER ERROR: got bad distributable configuration
2025-11-05T13:43:59.698373Z INFO: TTestServer started on Port 28057 GrpcPort 28700
TClient is connected to server localhost:28057
PQClient connected to localhost:28700
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:43:59.778237Z node 12 :HIVE WARN: HIVE#72057594037968897 Node(12, (0,0,0,0)) VolatileState: Unknown -> Disconnected
2025-11-05T13:43:59.778264Z node 12 :HIVE WARN: HIVE#72057594037968897 Node(12, (0,0,0,0)) VolatileState: Disconnected -> Connecting
2025-11-05T13:43:59.778554Z node 12 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpAlterSubDomain, opId: 281474976715657:0, at schemeshard:  72057594046644480
waiting...
2025-11-05T13:43:59.779276Z node 12 :HIVE WARN: HIVE#72057594037968897 Node(12, (0,0,0,0)) VolatileState: Connecting -> Connected
waiting...
2025-11-05T13:43:59.783536Z node 12 :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:43:59.932558Z node 12 :KQP_COMPILE_ACTOR ERROR: Compilation failed, self: [12:7569236640668445472: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:43:59.932846Z node 12 :KQP_SESSION WARN: SessionId: ydb://session/3?node_id=12&id=NWRlNTQyM2YtYmZlZWMwNDQtYjJjM2YzNzQtOGU2ZTNiMWY=, ActorId: [12:7569236640668445469:2314], ActorState: ExecuteState, TraceId: 01k9a4545s4y85kk2721pd1qk0, ReplyQueryCompileError, status SCHEME_ERROR remove tx with tx_id: 
2025-11-05T13:43:59.932933Z node 12 :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:43:59.933580Z node 12 :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:43:59.939185Z node 12 :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:43:59.956599Z node 12 :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 [12:7569236640668445748:2560] 
2025-11-05T13:44:00.676640Z node 12 :TX_CONVEYOR ERROR: fline=service.h:53;problem=unexpected event for task executor;ev_type=NActors::TEvents::TEvWakeup;
2025-11-05T13:44:04.674877Z node 12 :METADATA_PROVIDER ERROR: fline=table_exists.cpp:59;actor=TTableExistsActor;event=timeout;self_id=[12:7569236640668444735:2066];send_to=[0:7307199536658146131:7762515];
2025-11-05T13:44:04.674907Z node 12 :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:44:05.058763Z :WriteToTopic_Demo_33 INFO: TTopicSdkTestSetup started
2025-11-05T13:44:05.061008Z node 12 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:44:05.063743Z node 12 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][] pipe [12:7569236666438249831:2729] connected; active server actors: 1
2025-11-05T13:44:05.063801Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:44:05.063817Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:44:05.063853Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:44:05.063857Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] BALANCER INIT DONE for test-topic: (0, 72075186224037892) 
2025-11-05T13:44:05.063873Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:44:05.063921Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72057594046644480, NodeId 12, Generation 2
2025-11-05T13:44:05.063931Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:44:05.063954Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] doesn't have tx info
2025-11-05T13:44:05.063960Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:44:05.063962Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] no config, start with empty partitions and default config
2025-11-05T13:44:05.063964Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:44:05.063968Z node 12 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:44:05.063975Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037892] doesn't have tx writes info
2025-11-05T13:44:05.063985Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [12:7569236666438249829:2728], now have 1 active actors on pipe
2025-11-05T13:44:05.063990Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [12:7569236666438249862:2422], now have 1 active actors on pipe
2025-11-05T13:44:05.063992Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72075186224037892, NodeId 12, Generation 1
2025-11-05T13:44:05.064058Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236640668445075 RawX2: 51539609711 } 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:44:05.064080Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] Propose TxId 281474976715671, WriteId (empty maybe)
2025-11-05T13:44:05.064086Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state UNKNOWN
2025-11-05T13:44:05.064088Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State UNKNOWN
2025-11-05T13:44:05.064091Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:44:05.064092Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from UNKNOWN to PREPARING
2025-11-05T13:44:05.064096Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:44:05.064124Z node 12 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PREPARED MinStep: 1762350245103 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: 7569236640668445075 RawX2: 51539609711 } Partitions { }
2025-11-05T13:44:05.064138Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.064242Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.064252Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARING
2025-11-05T13:44:05.064253Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARING
2025-11-05T13:44:05.064255Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARING to PREPARED
2025-11-05T13:44:05.064348Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037892 TxId: 281474976715671
2025-11-05T13:44:05.064511Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [12:7569236666438249874:2755], now have 1 active actors on pipe
2025-11-05T13:44:05.064525Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715671 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350245110 MediatorID: 72057594046382081 TabletID: 72075186224037892
2025-11-05T13:44:05.064530Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARED
2025-11-05T13:44:05.064531Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARED
2025-11-05T13:44:05.064533Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARED to PLANNING
2025-11-05T13:44:05.064535Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] PlanStep 1762350245110, PlanTxId 281474976715671
2025-11-05T13:44:05.064538Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:44:05.064567Z node 12 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PLANNED MinStep: 1762350245103 MaxStep: 18446744073709551615 Step: 1762350245110 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: 7569236640668445075 RawX2: 51539609711 } Partitions { }
2025-11-05T13:44:05.064580Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.064660Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.064665Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PLANNING
2025-11-05T13:44:05.064666Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PLANNING
2025-11-05T13:44:05.064667Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNING to PLANNED
2025-11-05T13:44:05.064669Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxQueue.size 1
2025-11-05T13:44:05.064670Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] New ExecStep 1762350245110, ExecTxId 281474976715671
2025-11-05T13:44:05.064736Z node 12 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:44:05.064740Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNED to CALCULATING
2025-11-05T13:44:05.064748Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:44:05.064837Z node 12 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:44:05.064883Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] bootstrapping 0 [12:7569236666438249881:2426]
2025-11-05T13:44:05.065045Z node 12 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Initializing completed.
2025-11-05T13:44:05.065051Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] init complete for topic 'test-topic' partition 0 generation 1 [12:7569236666438249881:2426]
2025-11-05T13:44:05.065056Z node 12 :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:44:05.065110Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:44:05.065116Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.065129Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.065133Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:44:05.065134Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350245110, TxId 281474976715671, Partition 0
2025-11-05T13:44:05.065135Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.065136Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.065136Z node 12 :PQ_TX DEBUG: [TxId: 281474976715671] Handle TEvProposePartitionConfigResult
2025-11-05T13:44:05.065137Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:44:05.065138Z node 12 :PQ_TX DEBUG: [TxId: 281474976715671] Partition responses 1/1
2025-11-05T13:44:05.065139Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATING
2025-11-05T13:44:05.065141Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATING
2025-11-05T13:44:05.065141Z node 12 :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:44:05.065143Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATING FrontTxId 281474976715671
2025-11-05T13:44:05.065145Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:44:05.065147Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATING to CALCULATED
2025-11-05T13:44:05.065150Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:44:05.065208Z node 12 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: CALCULATED MinStep: 1762350245103 MaxStep: 18446744073709551615 Step: 1762350245110 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: 7569236640668445075 RawX2: 51539609711 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:44:05.065224Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.065414Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.065420Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATED
2025-11-05T13:44:05.065421Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATED
2025-11-05T13:44:05.065434Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATED FrontTxId 281474976715671
2025-11-05T13:44:05.065437Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATED to WAIT_RS
2025-11-05T13:44:05.065447Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:44:05.065449Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveParticipantsDecision 1
2025-11-05T13:44:05.065457Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS to EXECUTING
2025-11-05T13:44:05.065464Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 0, Expected 1
2025-11-05T13:44:05.065466Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350245110, TxId 281474976715671
2025-11-05T13:44:05.065469Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.065471Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.065492Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.065526Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:44:05.066071Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:44:05.066072Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] Handle TEvPQ::TEvTxCommitDone Step 1762350245110, TxId 281474976715671, Partition 0
2025-11-05T13:44:05.066076Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTING
2025-11-05T13:44:05.066077Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTING
2025-11-05T13:44:05.066079Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTING FrontTxId 281474976715671
2025-11-05T13:44:05.066080Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.066080Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:44:05.066082Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.066084Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId: 281474976715671 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:44:05.066089Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] complete TxId 281474976715671
2025-11-05T13:44:05.066126Z node 12 :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:44:05.066144Z node 12 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:44:05.066151Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] delete partitions for TxId 281474976715671
2025-11-05T13:44:05.066156Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTING to EXECUTED
2025-11-05T13:44:05.066159Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:44:05.066206Z node 12 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: EXECUTED MinStep: 1762350245103 MaxStep: 18446744073709551615 Step: 1762350245110 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: 7569236640668445075 RawX2: 51539609711 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:44:05.066235Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.066630Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:44:05.066645Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:44:05.066721Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.066729Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTED
2025-11-05T13:44:05.066730Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTED
2025-11-05T13:44:05.066732Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTED FrontTxId 281474976715671
2025-11-05T13:44:05.066735Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:44:05.066737Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:44:05.066738Z node 12 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:44:05.066740Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:44:05.066740Z node 12 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:44:05.066742Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] add an TxId 281474976715671 to the list for deletion
2025-11-05T13:44:05.066743Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:44:05.066746Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] delete key for TxId 281474976715671
2025-11-05T13:44:05.066751Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.066830Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.066835Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state DELETING
2025-11-05T13:44:05.066836Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State DELETING
2025-11-05T13:44:05.066837Z node 12 :PQ_TX INFO: [PQ: 72075186224037892] delete TxId 281474976715671
2025-11-05T13:44:05.067133Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:44:05.067318Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:44:05.067323Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:28700
2025-11-05T13:44:05.068139Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "test-topic" message_group_id: "src" }
2025-11-05T13:44:05.068156Z node 12 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:44:05.068163Z node 12 :PQ_WRITE_PROXY DEBUG: new session created cookie 1
2025-11-05T13:44:05.068398Z node 12 :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:44:05.068415Z node 12 :PQ_WRITE_PROXY INFO: session request cookie: 1 topic: "test-topic" message_group_id: "src" from ipv6:[::1]:49120
2025-11-05T13:44:05.068421Z node 12 :PQ_WRITE_PROXY INFO: write session:  cookie=1 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:49120 proto=v1  topic=test-topic durationSec=0
2025-11-05T13:44:05.068423Z node 12 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:44:05.068804Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId:  describe result for acl check
2025-11-05T13:44:05.068827Z node 12 :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:44:05.068832Z node 12 :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:44:05.068833Z node 12 :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:44:05.068843Z node 12 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [12:7569236666438249925:2434] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:44:05.068847Z node 12 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 1 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:44:05.068926Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 12, Generation: 1
2025-11-05T13:44:05.068934Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [12:7569236666438249928:2434], now have 1 active actors on pipe
2025-11-05T13:44:05.068938Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:44:05.068942Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:44:05.068960Z node 12 :PERSQUEUE INFO: new Cookie src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0 generated for partition 0 topic 'test-topic' owner src
2025-11-05T13:44:05.068973Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.068979Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.068985Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.068996Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:44:05.069016Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.069041Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:44:05.069045Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:44:05.069056Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.069072Z node 12 :PQ_WRITE_PROXY INFO: session inited cookie: 1 partition: 0 MaxSeqNo: 0 sessionId: src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0
2025-11-05T13:44:05.069216Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350245069 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:44:05.069228Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0" topic: "test-topic"
2025-11-05T13:44:05.069293Z :INFO: [/Root] MessageGroupId [src] SessionId [src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0] Write session: close. Timeout = 0 ms
2025-11-05T13:44:05.069299Z :INFO: [/Root] MessageGroupId [src] SessionId [src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0] Write session will now close
2025-11-05T13:44:05.069305Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0] Write session: aborting
2025-11-05T13:44:05.069410Z :INFO: [/Root] MessageGroupId [src] SessionId [src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:44:05.069416Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0] Write session: destroy
2025-11-05T13:44:05.069535Z node 12 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId: src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0 grpc read done: success: 0 data: 
2025-11-05T13:44:05.069541Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0 grpc read failed
2025-11-05T13:44:05.069545Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0 grpc closed
2025-11-05T13:44:05.069546Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|c2777a1b-7933f870-3a55bbb3-e4d1bab5_0 is DEAD
2025-11-05T13:44:05.069769Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:44:05.069807Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [12:7569236666438249928:2434] destroyed
2025-11-05T13:44:05.069819Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:44:05.069827Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.069829Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.069883Z :WriteToTopic_Demo_33 INFO: Topic created
2025-11-05T13:44:05.072277Z node 12 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:44:05.073016Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:44:05.073042Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:44:05.074925Z node 12 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][] pipe [12:7569236666438249972:2797] connected; active server actors: 1
2025-11-05T13:44:05.074981Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:44:05.075010Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:44:05.075015Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:44:05.075071Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:44:05.075072Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:44:05.075086Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] BALANCER INIT DONE for topic_A: (0, 72075186224037894) 
2025-11-05T13:44:05.075090Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] doesn't have tx info
2025-11-05T13:44:05.075091Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:44:05.075093Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] no config, start with empty partitions and default config
2025-11-05T13:44:05.075094Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:44:05.075098Z node 12 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:44:05.075101Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037894] doesn't have tx writes info
2025-11-05T13:44:05.075114Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [12:7569236666438249968:2795], now have 1 active actors on pipe
2025-11-05T13:44:05.075121Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [12:7569236666438250003:2448], now have 1 active actors on pipe
2025-11-05T13:44:05.075123Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientConnected TabletId 72075186224037894, NodeId 12, Generation 1
2025-11-05T13:44:05.075126Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientConnected TabletId 72057594046644480, NodeId 12, Generation 2
2025-11-05T13:44:05.075195Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236640668445075 RawX2: 51539609711 } 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:44:05.075220Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] Propose TxId 281474976715672, WriteId (empty maybe)
2025-11-05T13:44:05.075227Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state UNKNOWN
2025-11-05T13:44:05.075229Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State UNKNOWN
2025-11-05T13:44:05.075232Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:44:05.075235Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from UNKNOWN to PREPARING
2025-11-05T13:44:05.075244Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:44:05.075285Z node 12 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PREPARED MinStep: 1762350245117 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: 7569236640668445075 RawX2: 51539609711 } Partitions { }
2025-11-05T13:44:05.075304Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.075421Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.075431Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARING
2025-11-05T13:44:05.075433Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARING
2025-11-05T13:44:05.075436Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARING to PREPARED
2025-11-05T13:44:05.075560Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037894 TxId: 281474976715672
2025-11-05T13:44:05.075667Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [12:7569236666438250015:2823], now have 1 active actors on pipe
2025-11-05T13:44:05.075683Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715672 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350245124 MediatorID: 72057594046382081 TabletID: 72075186224037894
2025-11-05T13:44:05.075689Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARED
2025-11-05T13:44:05.075690Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARED
2025-11-05T13:44:05.075693Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARED to PLANNING
2025-11-05T13:44:05.075696Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] PlanStep 1762350245124, PlanTxId 281474976715672
2025-11-05T13:44:05.075700Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:44:05.075752Z node 12 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PLANNED MinStep: 1762350245117 MaxStep: 18446744073709551615 Step: 1762350245124 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: 7569236640668445075 RawX2: 51539609711 } Partitions { }
2025-11-05T13:44:05.075769Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.075855Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.075859Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PLANNING
2025-11-05T13:44:05.075861Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PLANNING
2025-11-05T13:44:05.075863Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNING to PLANNED
2025-11-05T13:44:05.075865Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxQueue.size 1
2025-11-05T13:44:05.075868Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] New ExecStep 1762350245124, ExecTxId 281474976715672
2025-11-05T13:44:05.075946Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNED to CALCULATING
2025-11-05T13:44:05.075951Z node 12 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:44:05.075958Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:44:05.076031Z node 12 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:44:05.076076Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] bootstrapping 0 [12:7569236666438250022:2452]
2025-11-05T13:44:05.076254Z node 12 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Initializing completed.
2025-11-05T13:44:05.076260Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] init complete for topic 'topic_A' partition 0 generation 1 [12:7569236666438250022:2452]
2025-11-05T13:44:05.076265Z node 12 :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:44:05.076318Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:44:05.076325Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.076339Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.076344Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350245124, TxId 281474976715672, Partition 0
2025-11-05T13:44:05.076345Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:44:05.076346Z node 12 :PQ_TX DEBUG: [TxId: 281474976715672] Handle TEvProposePartitionConfigResult
2025-11-05T13:44:05.076349Z node 12 :PQ_TX DEBUG: [TxId: 281474976715672] Partition responses 1/1
2025-11-05T13:44:05.076348Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.076350Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.076350Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATING
2025-11-05T13:44:05.076352Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATING
2025-11-05T13:44:05.076352Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:44:05.076354Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATING FrontTxId 281474976715672
2025-11-05T13:44:05.076356Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:44:05.076358Z node 12 :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:44:05.076361Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATING to CALCULATED
2025-11-05T13:44:05.076364Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:44:05.076416Z node 12 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: CALCULATED MinStep: 1762350245117 MaxStep: 18446744073709551615 Step: 1762350245124 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: 7569236640668445075 RawX2: 51539609711 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:44:05.076434Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.076584Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.076589Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATED
2025-11-05T13:44:05.076591Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATED
2025-11-05T13:44:05.076593Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATED FrontTxId 281474976715672
2025-11-05T13:44:05.076595Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATED to WAIT_RS
2025-11-05T13:44:05.076604Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:44:05.076606Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveParticipantsDecision 1
2025-11-05T13:44:05.076612Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS to EXECUTING
2025-11-05T13:44:05.076614Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350245124, TxId 281474976715672
2025-11-05T13:44:05.076617Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.076617Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 0, Expected 1
2025-11-05T13:44:05.076618Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.076639Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.076662Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:44:05.076776Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTxCommitDone Step 1762350245124, TxId 281474976715672, Partition 0
2025-11-05T13:44:05.076781Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTING
2025-11-05T13:44:05.076781Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:44:05.076782Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTING
2025-11-05T13:44:05.076784Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTING FrontTxId 281474976715672
2025-11-05T13:44:05.076785Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.076786Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:44:05.076786Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.076789Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId: 281474976715672 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:44:05.076794Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] complete TxId 281474976715672
2025-11-05T13:44:05.076830Z node 12 :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:44:05.076844Z node 12 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:44:05.076854Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] delete partitions for TxId 281474976715672
2025-11-05T13:44:05.076859Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTING to EXECUTED
2025-11-05T13:44:05.076861Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:44:05.076900Z node 12 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: EXECUTED MinStep: 1762350245117 MaxStep: 18446744073709551615 Step: 1762350245124 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: 7569236640668445075 RawX2: 51539609711 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:44:05.076920Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.077063Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.077068Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTED
2025-11-05T13:44:05.077069Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTED
2025-11-05T13:44:05.077071Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTED FrontTxId 281474976715672
2025-11-05T13:44:05.077073Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:44:05.077074Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:44:05.077077Z node 12 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:44:05.077078Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:44:05.077079Z node 12 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:44:05.077081Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] add an TxId 281474976715672 to the list for deletion
2025-11-05T13:44:05.077084Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:44:05.077086Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] delete key for TxId 281474976715672
2025-11-05T13:44:05.077091Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.077109Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:44:05.077113Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:44:05.077118Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:44:05.077181Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:44:05.077200Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.077204Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state DELETING
2025-11-05T13:44:05.077205Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State DELETING
2025-11-05T13:44:05.077207Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] delete TxId 281474976715672
2025-11-05T13:44:05.077394Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:44:05.077571Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:44:05.077576Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:28700
2025-11-05T13:44:05.078172Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:44:05.078248Z node 12 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:44:05.078255Z node 12 :PQ_WRITE_PROXY DEBUG: new session created cookie 2
2025-11-05T13:44:05.078353Z node 12 :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:44:05.078370Z node 12 :PQ_WRITE_PROXY INFO: session request cookie: 2 topic: "topic_A" message_group_id: "src" from ipv6:[::1]:49120
2025-11-05T13:44:05.078376Z node 12 :PQ_WRITE_PROXY INFO: write session:  cookie=2 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:49120 proto=v1  topic=topic_A durationSec=0
2025-11-05T13:44:05.078379Z node 12 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:44:05.078629Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId:  describe result for acl check
2025-11-05T13:44:05.078656Z node 12 :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:44:05.078662Z node 12 :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:44:05.078976Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350245078 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:44:05.078663Z node 12 :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:44:05.078673Z node 12 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [12:7569236666438250057:2460] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:44:05.078677Z node 12 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 2 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:44:05.078759Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 12, Generation: 1
2025-11-05T13:44:05.078765Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [12:7569236666438250060:2460], now have 1 active actors on pipe
2025-11-05T13:44:05.078769Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.078772Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.078785Z node 12 :PERSQUEUE INFO: new Cookie src|bb67c44e-7b596f85-1c539a11-2a2eb050_0 generated for partition 0 topic 'topic_A' owner src
2025-11-05T13:44:05.078790Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.078792Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.078796Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.078801Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:44:05.078813Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.078832Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.078834Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.085285Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|bb67c44e-7b596f85-1c539a11-2a2eb050_0" topic: "topic_A"
2025-11-05T13:44:05.078843Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.078852Z node 12 :PQ_WRITE_PROXY INFO: session inited cookie: 2 partition: 0 MaxSeqNo: 0 sessionId: src|bb67c44e-7b596f85-1c539a11-2a2eb050_0
2025-11-05T13:44:05.085447Z :INFO: [/Root] MessageGroupId [src] SessionId [src|bb67c44e-7b596f85-1c539a11-2a2eb050_0] Write session: close. Timeout = 0 ms
2025-11-05T13:44:05.085453Z :INFO: [/Root] MessageGroupId [src] SessionId [src|bb67c44e-7b596f85-1c539a11-2a2eb050_0] Write session will now close
2025-11-05T13:44:05.085458Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|bb67c44e-7b596f85-1c539a11-2a2eb050_0] Write session: aborting
2025-11-05T13:44:05.085713Z node 12 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId: src|bb67c44e-7b596f85-1c539a11-2a2eb050_0 grpc read done: success: 0 data: 
2025-11-05T13:44:05.085728Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|bb67c44e-7b596f85-1c539a11-2a2eb050_0 grpc read failed
2025-11-05T13:44:05.085733Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|bb67c44e-7b596f85-1c539a11-2a2eb050_0 grpc closed
2025-11-05T13:44:05.085735Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|bb67c44e-7b596f85-1c539a11-2a2eb050_0 is DEAD
2025-11-05T13:44:05.085892Z :INFO: [/Root] MessageGroupId [src] SessionId [src|bb67c44e-7b596f85-1c539a11-2a2eb050_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:44:05.085905Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:44:05.085936Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [12:7569236666438250060:2460] destroyed
2025-11-05T13:44:05.085945Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:44:05.085948Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.085950Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.086281Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|bb67c44e-7b596f85-1c539a11-2a2eb050_0] Write session is aborting and will not restart
2025-11-05T13:44:05.086300Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|bb67c44e-7b596f85-1c539a11-2a2eb050_0] Write session: destroy
2025-11-05T13:44:05.088551Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0] Write session: try to update token
2025-11-05T13:44:05.088655Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-11-05T13:44:05.088662Z :TRACE: [/Root] TRACE_EVENT DescribePartitionRequest  path=/Root/topic_A partition_id=0
2025-11-05T13:44:05.088679Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-11-05T13:44:05.088970Z node 12 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:44:05.088998Z node 12 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request path: "/Root/topic_A"
include_location: true
2025-11-05T13:44:05.089004Z node 12 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[12:7569236666438250069:2466]: Bootstrap
2025-11-05T13:44:05.089234Z node 12 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [12:7569236666438250069:2466]: Request location
2025-11-05T13:44:05.089273Z node 12 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [12:7569236666438250078:2467] connected; active server actors: 1
2025-11-05T13:44:05.089285Z node 12 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] addPartitionToResponse tabletId 72075186224037894, partitionId 0, NodeId 12, Generation 1
2025-11-05T13:44:05.089289Z node 12 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [12:7569236666438250069:2466]: Got location
2025-11-05T13:44:05.089301Z node 12 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [12:7569236666438250078:2467] disconnected; active server actors: 1
2025-11-05T13:44:05.089305Z node 12 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [12:7569236666438250078:2467] disconnected no session
2025-11-05T13:44:05.089453Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 12
    generation: 1
  }
}
2025-11-05T13:44:05.089460Z :TRACE: [/Root] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=12 pl_generation=1
2025-11-05T13:44:05.089464Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 12 exists in the endpoint pool.
2025-11-05T13:44:05.089468Z :TRACE: [/Root] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=12 Generation=1
2025-11-05T13:44:05.089470Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 12
2025-11-05T13:44:05.089597Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-11-05T13:44:05.089616Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } }
2025-11-05T13:44:05.089619Z :TRACE: [/Root] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-11-05T13:44:05.089696Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:44:05.089744Z node 12 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:44:05.089750Z node 12 :PQ_WRITE_PROXY DEBUG: new session created cookie 3
2025-11-05T13:44:05.089839Z node 12 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId:  grpc read done: success: 1 data: init_request { path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } }
2025-11-05T13:44:05.089859Z node 12 :PQ_WRITE_PROXY INFO: session request cookie: 3 path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } from ipv6:[::1]:49120
2025-11-05T13:44:05.089861Z node 12 :PQ_WRITE_PROXY INFO: write session:  cookie=3 sessionId= userAgent="topic server" ip=ipv6:[::1]:49120 proto=topic  topic=topic_A durationSec=0
2025-11-05T13:44:05.089870Z node 12 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:44:05.089878Z node 12 :PQ_WRITE_PROXY INFO: session to partition: 0, generation: 1
2025-11-05T13:44:05.090035Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId:  describe result for acl check
2025-11-05T13:44:05.090066Z node 12 :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:44:05.090070Z node 12 :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:44:05.090072Z node 12 :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:44:05.090077Z node 12 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [12:7569236666438250083:2469] (SourceId=test-message_group_id, PreferedPartition=0) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:44:05.090081Z node 12 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 3 sessionId:  partition: 0 expectedGeneration: 1
2025-11-05T13:44:05.090156Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 12, Generation: 1
2025-11-05T13:44:05.090165Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [12:7569236666438250086:2469], now have 1 active actors on pipe
2025-11-05T13:44:05.090170Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.090174Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.090196Z node 12 :PERSQUEUE INFO: new Cookie test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0 generated for partition 0 topic 'topic_A' owner test-message_group_id
2025-11-05T13:44:05.090208Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.090215Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.090224Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.090236Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:44:05.090260Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.090286Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.090291Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.090306Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.090324Z node 12 :PQ_WRITE_PROXY INFO: session inited cookie: 3 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0
2025-11-05T13:44:05.090439Z :DEBUG: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:44:05.090446Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350245090 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:44:05.090459Z :INFO: [/Root]  TraceId []  SessionId []  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0"
2025-11-05T13:44:05.090462Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0
2025-11-05T13:44:05.090493Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=1, txId=01k9a459700y34myj85wxtebgy, WriteCount=1, AckCount=0
2025-11-05T13:44:05.090504Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-11-05T13:44:05.090522Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:44:05.090525Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-11-05T13:44:05.090641Z node 12 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:44:05.090680Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP for a WriteId. SessionId: ydb://session/3?node_id=12&id=YzFhZWRiZDMtNWUzMmI0ZTMtZjE3ODQ2ZTktNzBhNmRlYWE= TxId: 01k9a459700y34myj85wxtebgy
2025-11-05T13:44:05.090724Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 12, Generation: 1
2025-11-05T13:44:05.090731Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [12:7569236666438250089:2469], now have 1 active actors on pipe
2025-11-05T13:44:05.090872Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of the request to KQP for the WriteId. SessionId: ydb://session/3?node_id=12&id=YzFhZWRiZDMtNWUzMmI0ZTMtZjE3ODQ2ZTktNzBhNmRlYWE= TxId: 01k9a459700y34myj85wxtebgy Status: SUCCESS
2025-11-05T13:44:05.090878Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) SessionId: ydb://session/3?node_id=12&id=YzFhZWRiZDMtNWUzMmI0ZTMtZjE3ODQ2ZTktNzBhNmRlYWE= TxId: 01k9a459700y34myj85wxtebgy WriteId: {12, 281474976715673}
2025-11-05T13:44:05.090889Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.090894Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.090899Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] partition {0, {12, 281474976715673}, 100000} for WriteId {12, 281474976715673}
2025-11-05T13:44:05.090928Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvSubscribeLock for WriteId {12, 281474976715673}
2025-11-05T13:44:05.090947Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.090963Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 12 Status: STATUS_SUBSCRIBED
2025-11-05T13:44:05.090970Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {12, 281474976715673}, TxId (empty maybe), Status STATUS_UNSPECIFIED
2025-11-05T13:44:05.090972Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] subscribed WriteId {12, 281474976715673}
2025-11-05T13:44:05.091116Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.091198Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715673}, 100000}:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:44:05.091257Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715673}, 100000}:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:44:05.091296Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateInit] bootstrapping {0, {12, 281474976715673}, 100000} [12:7569236666438250095:2471]
2025-11-05T13:44:05.091464Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715673}, 100000}:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:44:05.091578Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715673}, 100000}:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:44:05.091605Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715673}, 100000}:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:44:05.091651Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:44:05.091667Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataStep
2025-11-05T13:44:05.091671Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715673}, 100000}:Initializer] Start initializing step TInitEndWriteTimestampStep
2025-11-05T13:44:05.091673Z node 12 :PERSQUEUE INFO: [topic_A:{0, {12, 281474976715673}, 100000}:TInitEndWriteTimestampStep] Initializing EndWriteTimestamp skipped because already initialized.
2025-11-05T13:44:05.091675Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715673}, 100000}:Initializer] Initializing completed.
2025-11-05T13:44:05.091678Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateInit] init complete for topic 'topic_A' partition {0, {12, 281474976715673}, 100000} generation 1 [12:7569236666438250095:2471]
2025-11-05T13:44:05.091682Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateInit] SYNC INIT topic topic_A partitition {0, {12, 281474976715673}, 100000} so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:44:05.091685Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Process pending events. Count 0
2025-11-05T13:44:05.091686Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.091688Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.091711Z node 12 :PERSQUEUE INFO: new Cookie test-message_group_id|7505ff26-a36cf016-2129061b-e3acfca1_0 generated for partition {0, {12, 281474976715673}, 100000} topic 'topic_A' owner test-message_group_id
2025-11-05T13:44:05.091718Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.091720Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.091723Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.091726Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyOwnerOk. Partition: {0, {12, 281474976715673}, 100000}
2025-11-05T13:44:05.091733Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.091742Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=12&id=YzFhZWRiZDMtNWUzMmI0ZTMtZjE3ODQ2ZTktNzBhNmRlYWE= TxId: 01k9a459700y34myj85wxtebgy
2025-11-05T13:44:05.091794Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=12&id=YzFhZWRiZDMtNWUzMmI0ZTMtZjE3ODQ2ZTktNzBhNmRlYWE= TxId: 01k9a459700y34myj85wxtebgy Status: SUCCESS
2025-11-05T13:44:05.091810Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.091815Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.091823Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.091847Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.091851Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.091866Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Reserve bytes in transaction. Partition: 0, WriteId: { NodeId: 12 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:44:05.091882Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-11-05T13:44:05.091896Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:44:05.091919Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.091923Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.091930Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Write in transaction. Partition: 0, WriteId: { NodeId: 12 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:44:05.091941Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 1 partNo : 0 messageNo: 1 size 16457 offset: -1
2025-11-05T13:44:05.091959Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.091967Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.091980Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {12, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 1 partNo 0
2025-11-05T13:44:05.092007Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {12, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 16546 count 1 nextOffset 1 batches 1
2025-11-05T13:44:05.092015Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.092061Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Add new write blob: topic 'topic_A' partition {0, {12, 281474976715673}, 100000} compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 D0000100000_00000000000000000000_00000_0000000001_00000| size 16536 WTime 1762350245091
2025-11-05T13:44:05.092089Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:44:05.092099Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 100000 offset 0 partNo 0 count 1 size 16536
2025-11-05T13:44:05.092228Z node 12 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 100000 offset 0 count 1 size 16536 actorID [12:7569236666438249998:2451]
2025-11-05T13:44:05.092245Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 16479 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:44:05.092248Z node 12 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 1 parts 0 size 16536
2025-11-05T13:44:05.092256Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {12, 281474976715673}, 100000}
2025-11-05T13:44:05.092269Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-11-05T13:44:05.092269Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {12, 281474976715673}, 100000}, SeqNo: 1, partNo: 0, Offset: 0 is stored on disk
2025-11-05T13:44:05.092279Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:44:05.092283Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.092286Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.092399Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:44:05.092424Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_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:44:05.092430Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=01k9a459700y34myj85wxtebgy, WriteCount=1, AckCount=1
2025-11-05T13:44:05.092575Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-11-05T13:44:05.092903Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [12:7569236666438250111:2856], now have 1 active actors on pipe
2025-11-05T13:44:05.092935Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236666438250108 RawX2: 4503651166980512 } TxId: 281474976715674 Data { Operations { PartitionId: 0 Path: "/Root/topic_A" SupportivePartition: 100000 } Op: Commit SendingShards: 72075186224037894 ReceivingShards: 72075186224037894 Immediate: true WriteId { NodeId: 12 KeyId: 281474976715673 } }
2025-11-05T13:44:05.092943Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] PartitionId {0, {12, 281474976715673}, 100000} for WriteId {12, 281474976715673}
2025-11-05T13:44:05.092947Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715674 has WriteId {12, 281474976715673}
2025-11-05T13:44:05.092950Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] immediate transaction
2025-11-05T13:44:05.092961Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Send TEvGetWriteInfoRequest for TxId (empty maybe)
2025-11-05T13:44:05.092966Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.092969Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] The Tx (empty maybe) is waiting for TEvGetWriteInfoResponse
2025-11-05T13:44:05.092969Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoRequest
2025-11-05T13:44:05.092970Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still preprocessing - waiting for something
2025-11-05T13:44:05.092978Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Send TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:44:05.092984Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:44:05.092987Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Received TEvGetWriteInfoResponse for TxId (empty maybe)
2025-11-05T13:44:05.092989Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.092994Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.092999Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::CommitWriteOperations TxId: (empty maybe)
2025-11-05T13:44:05.093004Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] t.WriteInfo->BodyKeys.size=0, t.WriteInfo->BlobsFromHead.size=1
2025-11-05T13:44:05.093010Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Head=Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0, NewHead=Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:44:05.093019Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 1 partNo 0
2025-11-05T13:44:05.093034Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 16546 count 1 nextOffset 1 batches 1
2025-11-05T13:44:05.093042Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] schedule TEvPersQueue::TEvProposeTransactionResult(COMPLETE), reason=
2025-11-05T13:44:05.093050Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.093081Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Add new write blob: topic 'topic_A' partition 0 compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 d0000000000_00000000000000000000_00000_0000000001_00000| size 16536 WTime 1762350245092
2025-11-05T13:44:05.093111Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:44:05.093114Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 0 partNo 0 count 1 size 16536
2025-11-05T13:44:05.093254Z node 12 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 0 count 1 size 16536 actorID [12:7569236666438249998:2451]
2025-11-05T13:44:05.093272Z node 12 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 0 offset 0 partno 0 count 1 parts 0 size 16536
2025-11-05T13:44:05.093274Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 16479
2025-11-05T13:44:05.093284Z node 12 :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:44:05.093290Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer send read request for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 1 rrg 0
2025-11-05T13:44:05.093293Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.093293Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.093299Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTransactionCompleted WriteId {12, 281474976715673}
2025-11-05T13:44:05.093301Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvPQ::TEvDeletePartition to partition {0, {12, 281474976715673}, 100000}
2025-11-05T13:44:05.093316Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Handle TEvPQ::TEvDeletePartition
2025-11-05T13:44:05.093327Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] read cookie 0 Topic 'topic_A' partition 0 user test-consumer offset 0 count 1 size 1024000 endOffset 1 max time lag 0ms effective offset 0
2025-11-05T13:44:05.093332Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] read cookie 0 added 0 blobs, size 0 count 0 last offset 0, current partition end offset: 1
2025-11-05T13:44:05.093345Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Reading cookie 0. All data is from uncompacted head.
2025-11-05T13:44:05.093347Z node 12 :PERSQUEUE DEBUG: FormAnswer for 0 blobs
2025-11-05T13:44:05.093359Z node 12 :PERSQUEUE DEBUG: Topic 'topic_A' partition 0 user test-consumer readTimeStamp done, result 1762350245091 queuesize 0 startOffset 0
2025-11-05T13:44:05.093363Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:44:05.093365Z node 12 :PERSQUEUE DEBUG: CacheProxy. Delete blobs from D0000100000(+) to D0000100001(-)
2025-11-05T13:44:05.093419Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 12 Status: STATUS_NOT_FOUND
2025-11-05T13:44:05.093440Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {12, 281474976715673}, TxId 281474976715674, Status STATUS_SUBSCRIBED
2025-11-05T13:44:05.093444Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] there is already a transaction TxId 281474976715674 for WriteId {12, 281474976715673}
2025-11-05T13:44:05.093465Z node 12 :PERSQUEUE DEBUG: Deleting head blob in L1. Partition 100000 offset 0 count 1 actorID [12:7569236666438249998:2451]
2025-11-05T13:44:05.093484Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.093488Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.093491Z node 12 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 1 parts 0
2025-11-05T13:44:05.093500Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvDeletePartitionDone {0, {12, 281474976715673}, 100000}
2025-11-05T13:44:05.093502Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] DeletePartition {0, {12, 281474976715673}, 100000}
2025-11-05T13:44:05.093506Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvUnsubscribeLock for WriteId {12, 281474976715673}
2025-11-05T13:44:05.093508Z node 12 :PQ_TX WARN: [PQ: 72075186224037894] Unknown transaction 281474976715674
2025-11-05T13:44:05.093514Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.093604Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.095231Z node 12 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:44:05.095677Z node 12 :TX_PROXY ERROR: Actor# [12:7569236666438250130:2863] txid# 281474976715675, issues: { message: "Check failed: path: \'/Root/topic_A\', error: path exist, request accepts it (id: [OwnerId: 72057594046644480, LocalPathId: 10], type: EPathTypePersQueueGroup, state: EPathStateNoChanges), source_location: ydb/core/tx/schemeshard/schemeshard__operation_create_pq.cpp:345" severity: 1 }
2025-11-05T13:44:05.095874Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:44:05.096000Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:44:05.096003Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:28700
2025-11-05T13:44:05.096548Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:44:05.096596Z node 12 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:44:05.096602Z node 12 :PQ_WRITE_PROXY DEBUG: new session created cookie 4
2025-11-05T13:44:05.096664Z node 12 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:44:05.096678Z node 12 :PQ_WRITE_PROXY INFO: session request cookie: 4 topic: "topic_A" message_group_id: "src" from ipv6:[::1]:49120
2025-11-05T13:44:05.096682Z node 12 :PQ_WRITE_PROXY INFO: write session:  cookie=4 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:49120 proto=v1  topic=topic_A durationSec=0
2025-11-05T13:44:05.096684Z node 12 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:44:05.096851Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId:  describe result for acl check
2025-11-05T13:44:05.096874Z node 12 :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:44:05.096878Z node 12 :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:44:05.096879Z node 12 :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:44:05.096887Z node 12 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [12:7569236666438250141:2482] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:44:05.096889Z node 12 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 4 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:44:05.096963Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 12, Generation: 1
2025-11-05T13:44:05.096969Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [12:7569236666438250144:2482], now have 1 active actors on pipe
2025-11-05T13:44:05.096973Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.096976Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.096985Z node 12 :PERSQUEUE INFO: new Cookie src|17ab2246-19dc1cac-849950a2-63ea54d8_0 generated for partition 0 topic 'topic_A' owner src
2025-11-05T13:44:05.096988Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.096990Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.096994Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.096998Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:44:05.097010Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.097029Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.097034Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.097042Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.097051Z node 12 :PQ_WRITE_PROXY INFO: session inited cookie: 4 partition: 0 MaxSeqNo: 0 sessionId: src|17ab2246-19dc1cac-849950a2-63ea54d8_0
2025-11-05T13:44:05.097180Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350245097 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:44:05.097195Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|17ab2246-19dc1cac-849950a2-63ea54d8_0" topic: "topic_A"
2025-11-05T13:44:05.097259Z :INFO: [/Root] MessageGroupId [src] SessionId [src|17ab2246-19dc1cac-849950a2-63ea54d8_0] Write session: close. Timeout = 0 ms
2025-11-05T13:44:05.097264Z :INFO: [/Root] MessageGroupId [src] SessionId [src|17ab2246-19dc1cac-849950a2-63ea54d8_0] Write session will now close
2025-11-05T13:44:05.097268Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|17ab2246-19dc1cac-849950a2-63ea54d8_0] Write session: aborting
2025-11-05T13:44:05.097357Z :INFO: [/Root] MessageGroupId [src] SessionId [src|17ab2246-19dc1cac-849950a2-63ea54d8_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:44:05.097360Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|17ab2246-19dc1cac-849950a2-63ea54d8_0] Write session: destroy
2025-11-05T13:44:05.097464Z node 12 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: src|17ab2246-19dc1cac-849950a2-63ea54d8_0 grpc read done: success: 0 data: 
2025-11-05T13:44:05.097471Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: src|17ab2246-19dc1cac-849950a2-63ea54d8_0 grpc read failed
2025-11-05T13:44:05.097477Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: src|17ab2246-19dc1cac-849950a2-63ea54d8_0 grpc closed
2025-11-05T13:44:05.097479Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: src|17ab2246-19dc1cac-849950a2-63ea54d8_0 is DEAD
2025-11-05T13:44:05.097667Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:44:05.097704Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [12:7569236666438250144:2482] destroyed
2025-11-05T13:44:05.097713Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:44:05.097720Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.097722Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.098853Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=2, txId=01k9a4597a22rxzdzxzxtxe2g2, WriteCount=1, AckCount=0
2025-11-05T13:44:05.098865Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 2 to 2
2025-11-05T13:44:05.098878Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:44:05.098880Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 2
2025-11-05T13:44:05.098977Z node 12 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:44:05.099026Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP for a WriteId. SessionId: ydb://session/3?node_id=12&id=NTY2Njg1MWMtNThhMDgwMGItMjY5Yzk4ZGEtOTRjYjgzOGQ= TxId: 01k9a4597a22rxzdzxzxtxe2g2
2025-11-05T13:44:05.099084Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [12:7569236666438250153:2469], now have 1 active actors on pipe
2025-11-05T13:44:05.099083Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 12, Generation: 1
2025-11-05T13:44:05.099195Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of the request to KQP for the WriteId. SessionId: ydb://session/3?node_id=12&id=NTY2Njg1MWMtNThhMDgwMGItMjY5Yzk4ZGEtOTRjYjgzOGQ= TxId: 01k9a4597a22rxzdzxzxtxe2g2 Status: SUCCESS
2025-11-05T13:44:05.099201Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) SessionId: ydb://session/3?node_id=12&id=NTY2Njg1MWMtNThhMDgwMGItMjY5Yzk4ZGEtOTRjYjgzOGQ= TxId: 01k9a4597a22rxzdzxzxtxe2g2 WriteId: {12, 281474976715676}
2025-11-05T13:44:05.099213Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.099217Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.099225Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] partition {0, {12, 281474976715676}, 100001} for WriteId {12, 281474976715676}
2025-11-05T13:44:05.099252Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvSubscribeLock for WriteId {12, 281474976715676}
2025-11-05T13:44:05.099268Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.099295Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715676 LockNode: 12 Status: STATUS_SUBSCRIBED
2025-11-05T13:44:05.099301Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {12, 281474976715676}, TxId (empty maybe), Status STATUS_UNSPECIFIED
2025-11-05T13:44:05.099303Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] subscribed WriteId {12, 281474976715676}
2025-11-05T13:44:05.099424Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.099496Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715676}, 100001}:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:44:05.099548Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715676}, 100001}:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:44:05.099582Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateInit] bootstrapping {0, {12, 281474976715676}, 100001} [12:7569236666438250159:2487]
2025-11-05T13:44:05.099738Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715676}, 100001}:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:44:05.099806Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715676}, 100001}:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:44:05.099829Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715676}, 100001}:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:44:05.099853Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715676}, 100001}:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:44:05.099867Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715676}, 100001}:Initializer] Start initializing step TInitDataStep
2025-11-05T13:44:05.099871Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715676}, 100001}:Initializer] Start initializing step TInitEndWriteTimestampStep
2025-11-05T13:44:05.099873Z node 12 :PERSQUEUE INFO: [topic_A:{0, {12, 281474976715676}, 100001}:TInitEndWriteTimestampStep] Initializing EndWriteTimestamp skipped because already initialized.
2025-11-05T13:44:05.099874Z node 12 :PERSQUEUE DEBUG: [topic_A:{0, {12, 281474976715676}, 100001}:Initializer] Initializing completed.
2025-11-05T13:44:05.099877Z node 12 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateInit] init complete for topic 'topic_A' partition {0, {12, 281474976715676}, 100001} generation 1 [12:7569236666438250159:2487]
2025-11-05T13:44:05.099880Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateInit] SYNC INIT topic topic_A partitition {0, {12, 281474976715676}, 100001} so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:44:05.099883Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Process pending events. Count 0
2025-11-05T13:44:05.099884Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.099885Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.099901Z node 12 :PERSQUEUE INFO: new Cookie test-message_group_id|7d7868f4-46d3244b-71a6989d-52ec27c5_0 generated for partition {0, {12, 281474976715676}, 100001} topic 'topic_A' owner test-message_group_id
2025-11-05T13:44:05.099907Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.099909Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.099914Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.099917Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyOwnerOk. Partition: {0, {12, 281474976715676}, 100001}
2025-11-05T13:44:05.099924Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.099932Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=12&id=NTY2Njg1MWMtNThhMDgwMGItMjY5Yzk4ZGEtOTRjYjgzOGQ= TxId: 01k9a4597a22rxzdzxzxtxe2g2
2025-11-05T13:44:05.099983Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=12&id=NTY2Njg1MWMtNThhMDgwMGItMjY5Yzk4ZGEtOTRjYjgzOGQ= TxId: 01k9a4597a22rxzdzxzxtxe2g2 Status: SUCCESS
2025-11-05T13:44:05.099996Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.100001Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.100010Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:44:05.100036Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.100042Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.100054Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Reserve bytes in transaction. Partition: 0, WriteId: { NodeId: 12 KeyId: 281474976715676 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:44:05.100070Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 2
2025-11-05T13:44:05.100080Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:44:05.100100Z node 12 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:44:05.100105Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:44:05.100112Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Write in transaction. Partition: 0, WriteId: { NodeId: 12 KeyId: 281474976715676 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:44:05.100121Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 0 messageNo: 1 size 16457 offset: -1
2025-11-05T13:44:05.100136Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.100143Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.100155Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {12, 281474976715676}, 100001} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 0
2025-11-05T13:44:05.100176Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Topic 'topic_A' partition {0, {12, 281474976715676}, 100001} part blob complete sourceId '\0test-message_group_id' seqNo 2 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 16546 count 1 nextOffset 1 batches 1
2025-11-05T13:44:05.100184Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.100225Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Add new write blob: topic 'topic_A' partition {0, {12, 281474976715676}, 100001} compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 D0000100001_00000000000000000000_00000_0000000001_00000| size 16536 WTime 1762350245099
2025-11-05T13:44:05.100252Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:44:05.100261Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 100001 offset 0 partNo 0 count 1 size 16536
2025-11-05T13:44:05.100392Z node 12 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 100001 offset 0 count 1 size 16536 actorID [12:7569236666438249998:2451]
2025-11-05T13:44:05.100410Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 16479 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:44:05.100416Z node 12 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 100001 offset 0 partno 0 count 1 parts 0 size 16536
2025-11-05T13:44:05.100418Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {12, 281474976715676}, 100001}
2025-11-05T13:44:05.100423Z node 12 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 1  requestId: <none> cookie: 2
2025-11-05T13:44:05.100423Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {12, 281474976715676}, 100001}, SeqNo: 2, partNo: 0, Offset: 0 is stored on disk
2025-11-05T13:44:05.100429Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:44:05.100435Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.100437Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.100535Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:44:05.100557Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 2 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:44:05.100562Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] OnAck: seqNo=2, txId=01k9a4597a22rxzdzxzxtxe2g2, WriteCount=1, AckCount=1
2025-11-05T13:44:05.100695Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 2
2025-11-05T13:44:05.100981Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236666438250172 RawX2: 4503651166980533 } TxId: 281474976715677 Data { Operations { PartitionId: 0 Path: "/Root/topic_A" SupportivePartition: 100001 } Op: Commit SendingShards: 72075186224037894 ReceivingShards: 72075186224037894 Immediate: true WriteId { NodeId: 12 KeyId: 281474976715676 } }
2025-11-05T13:44:05.100990Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] PartitionId {0, {12, 281474976715676}, 100001} for WriteId {12, 281474976715676}
2025-11-05T13:44:05.100994Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715677 has WriteId {12, 281474976715676}
2025-11-05T13:44:05.100996Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] immediate transaction
2025-11-05T13:44:05.101007Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Send TEvGetWriteInfoRequest for TxId (empty maybe)
2025-11-05T13:44:05.101009Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.101015Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoRequest
2025-11-05T13:44:05.101015Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] The Tx (empty maybe) is waiting for TEvGetWriteInfoResponse
2025-11-05T13:44:05.101017Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still preprocessing - waiting for something
2025-11-05T13:44:05.101024Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Send TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:44:05.101028Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:44:05.101033Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Received TEvGetWriteInfoResponse for TxId (empty maybe)
2025-11-05T13:44:05.101035Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.101039Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.101043Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::CommitWriteOperations TxId: (empty maybe)
2025-11-05T13:44:05.101048Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] t.WriteInfo->BodyKeys.size=0, t.WriteInfo->BlobsFromHead.size=1
2025-11-05T13:44:05.101055Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Head=Offset 0 PartNo 0 PackedSize 16536 count 1 nextOffset 1 batches 1, NewHead=Offset 1 PartNo 0 PackedSize 0 count 0 nextOffset 1 batches 0
2025-11-05T13:44:05.101064Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 0
2025-11-05T13:44:05.101078Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 2 partNo 0 FormedBlobsCount 0 NewHead: Offset 1 PartNo 0 PackedSize 16546 count 1 nextOffset 2 batches 1
2025-11-05T13:44:05.101086Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] schedule TEvPersQueue::TEvProposeTransactionResult(COMPLETE), reason=
2025-11-05T13:44:05.101093Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.101126Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Add new write blob: topic 'topic_A' partition 0 compactOffset 1,1 HeadOffset 0 endOffset 1 curOffset 2 d0000000000_00000000000000000001_00000_0000000001_00000| size 16536 WTime 1762350245100
2025-11-05T13:44:05.101156Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:44:05.101169Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 1 partNo 0 count 1 size 16536
2025-11-05T13:44:05.101272Z node 12 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 1 count 1 size 16536 actorID [12:7569236666438249998:2451]
2025-11-05T13:44:05.101281Z node 12 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 0 offset 1 partno 0 count 1 parts 0 size 16536
2025-11-05T13:44:05.101352Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 16479
2025-11-05T13:44:05.101368Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.101372Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.101378Z node 12 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTransactionCompleted WriteId {12, 281474976715676}
2025-11-05T13:44:05.101381Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvPQ::TEvDeletePartition to partition {0, {12, 281474976715676}, 100001}
2025-11-05T13:44:05.101386Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Handle TEvPQ::TEvDeletePartition
2025-11-05T13:44:05.101422Z node 12 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:44:05.101439Z node 12 :PERSQUEUE DEBUG: CacheProxy. Delete blobs from D0000100001(+) to D0000100002(-)
2025-11-05T13:44:05.101461Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715676 LockNode: 12 Status: STATUS_NOT_FOUND
2025-11-05T13:44:05.101466Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {12, 281474976715676}, TxId 281474976715677, Status STATUS_SUBSCRIBED
2025-11-05T13:44:05.101468Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] there is already a transaction TxId 281474976715677 for WriteId {12, 281474976715676}
2025-11-05T13:44:05.101576Z node 12 :PERSQUEUE DEBUG: Deleting head blob in L1. Partition 100001 offset 0 count 1 actorID [12:7569236666438249998:2451]
2025-11-05T13:44:05.101601Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.101606Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {12, 281474976715676}, 100001}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.101607Z node 12 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037894' partition 100001 offset 0 partno 0 count 1 parts 0
2025-11-05T13:44:05.101651Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvDeletePartitionDone {0, {12, 281474976715676}, 100001}
2025-11-05T13:44:05.101659Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] DeletePartition {0, {12, 281474976715676}, 100001}
2025-11-05T13:44:05.101664Z node 12 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvUnsubscribeLock for WriteId {12, 281474976715676}
2025-11-05T13:44:05.101671Z node 12 :PQ_TX WARN: [PQ: 72075186224037894] Unknown transaction 281474976715677
2025-11-05T13:44:05.101678Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:44:05.101753Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:44:05.102000Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: close. Timeout 0.000000s
2025-11-05T13:44:05.188892Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session will now close
2025-11-05T13:44:05.165379Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.188907Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: aborting
2025-11-05T13:44:05.165393Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.176624Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.176631Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.189075Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: gracefully shut down, all writes complete
2025-11-05T13:44:05.189082Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0]  PartitionId [0]  Generation [1] Write session: destroy
2025-11-05T13:44:05.189241Z node 12 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0 grpc read done: success: 0 data: 
2025-11-05T13:44:05.189250Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0 grpc read failed
2025-11-05T13:44:05.189259Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0 grpc closed
2025-11-05T13:44:05.189265Z node 12 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|3c76f9cd-caeedb2c-bd768407-ef578b38_0 is DEAD
2025-11-05T13:44:05.189569Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:44:05.189586Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:44:05.189589Z node 12 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:44:05.189665Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [12:7569236666438250153:2469] destroyed
2025-11-05T13:44:05.189680Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [12:7569236666438250086:2469] destroyed
2025-11-05T13:44:05.189683Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [12:7569236666438250089:2469] destroyed
2025-11-05T13:44:05.189691Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:44:05.189696Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.189697Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.265721Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.265734Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:44:05.276971Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:44:05.276983Z node 12 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
