app.log.2026-06-29

Latest changes applied: initial drive time fix (2026-07-22)
2026-07-06 11:22:39,999 - [124697] - src.utils.log - INFO - 📥 Inserting into ServiceCore.WorkOrderAutoGenerationPublishHistory: 5 rows in batches of 25000 (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:40,366 - [124697] - src.utils.log - INFO - 📤 Inserting batch 1/1 (0 to 5) into ServiceCore.WorkOrderAutoGenerationPublishHistory - __SPLIT__
2026-07-06 11:22:41,546 - [124697] - src.utils.log - INFO - ✅ All 5 rows inserted successfully into ServiceCore.WorkOrderAutoGenerationPublishHistory in 1 batches - __SPLIT__
2026-07-06 11:22:41,621 - [124697] - src.utils.log - INFO - 🔍 Fetching data: 
        SELECT 
            WorkOrderAutoGenerationPublishHistoryId,
            WorkOrderNo,
            ServiceSetupId
        FROM ServiceCore.WorkOrderAutoGenerationPublishHistory
        WHERE
    ServiceSetupId IN (150620, 150636) AND WorkOrderNo IN ('692037', '8992905', '6887219', '1757046', '8189834') AND GenerateWorkOrderHistoryId = 124697;... (Thread: ThreadPoolExecutor-9_0) - __SPLIT__
2026-07-06 11:22:42,115 - [124697] - src.utils.log - INFO - ✅ Fetched 5 rows - __SPLIT__
2026-07-06 11:22:42,190 - [124697] - src.utils.log - INFO - 🏁 Final merged rows: 5 - __SPLIT__
2026-07-06 11:22:42,267 - [124697] - src.utils.log - INFO - Sequential Insertion in work order tables begin - __SPLIT__
2026-07-06 11:22:42,340 - [124697] - src.utils.log - INFO - Checking if all rows exist in parent table or not - __SPLIT__
2026-07-06 11:22:42,413 - [124697] - src.utils.log - INFO - 📥 Inserting into ServiceCore.WorkOrderServices: 5 rows in batches of 25000 (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:42,765 - [124697] - src.utils.log - INFO - 📤 Inserting batch 1/1 (0 to 5) into ServiceCore.WorkOrderServices - __SPLIT__
2026-07-06 11:22:43,793 - [124697] - src.utils.log - INFO - ✅ All 5 rows inserted successfully into ServiceCore.WorkOrderServices in 1 batches - __SPLIT__
2026-07-06 11:22:43,863 - [124697] - src.utils.log - INFO - 📥 Empty dataframe of ServiceAuto.WorkOrderAppliedDiscount: - __SPLIT__
2026-07-06 11:22:43,983 - [124697] - src.utils.log - INFO - 📥 Empty dataframe of ServiceCore.WorkOrderSalesPersonCommission: - __SPLIT__
2026-07-06 11:22:44,062 - [124697] - src.utils.log - INFO - 📥 Empty dataframe of ServiceAuto.WorkOrderCommissionAdjustment: - __SPLIT__
2026-07-06 11:22:44,133 - [124697] - src.utils.log - INFO - Checking if all rows exist in parent table or not - __SPLIT__
2026-07-06 11:22:44,203 - [124697] - src.utils.log - INFO - 📥 Inserting into ServiceCore.WorkOrderCrew: 5 rows in batches of 25000 (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:44,550 - [124697] - src.utils.log - INFO - 📤 Inserting batch 1/1 (0 to 5) into ServiceCore.WorkOrderCrew - __SPLIT__
2026-07-06 11:22:45,572 - [124697] - src.utils.log - INFO - ✅ All 5 rows inserted successfully into ServiceCore.WorkOrderCrew in 1 batches - __SPLIT__
2026-07-06 11:22:45,643 - [124697] - src.utils.log - INFO - 📥 Empty dataframe of ServiceCore.WorkorderSourceMapping: - __SPLIT__
2026-07-06 11:22:45,719 - [124697] - src.utils.log - INFO - 📥 Empty dataframe of CRM.LeadNote: - __SPLIT__
2026-07-06 11:22:45,796 - [124697] - src.utils.log - INFO - Checking if all rows exist in parent table or not - __SPLIT__
2026-07-06 11:22:45,866 - [124697] - src.utils.log - INFO - 📥 Inserting into ServiceCore.WorkOrderAutoGenerationPublishServices: 5 rows in batches of 25000 (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:46,218 - [124697] - src.utils.log - INFO - 📤 Inserting batch 1/1 (0 to 5) into ServiceCore.WorkOrderAutoGenerationPublishServices - __SPLIT__
2026-07-06 11:22:47,243 - [124697] - src.utils.log - INFO - ✅ All 5 rows inserted successfully into ServiceCore.WorkOrderAutoGenerationPublishServices in 1 batches - __SPLIT__
2026-07-06 11:22:47,317 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT ss.ServiceSetupId as SetupId, ss.FrequencyScheduleId as setup_frequency_schedule_id, ss.AccountNumber, ss.CompanyId, 
        ss.BillingLocationId, ss.ServiceLocationId, ss.TaxSysName, ss.TermId,  ss.TaxPercent, ss.PoNumber, ss.IsTaxExempt,
        ss.DisplayServiceAsSeparateLineItem, ss.GenerateInvoice, ss.IsGenerateInvoiceforInitalSetup, 
        ss.IsGenerateInvoiceforInitalSetupBilling, ss.IsBilling, t.NetDueIn, ptm.PaymentType, ssb.* 
        FROM ServiceCore.ServiceSetup ss LEFT JOIN ServiceCore.ServiceSetupBilling ssb 
        ON ss.ServiceSetupId = ssb.ServiceSetupId LEFT JOIN Billing.PaymentTypeMaster ptm ON 
        ptm.PaymentTypeMasterId = ssb.PaymentTypeMasterId left join Billing.Term t on ss.TermId = t.TermId 
        WHERE ss.ServiceSetupId in (150620, 150636)... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:47,664 - [124697] - src.utils.log - INFO - ✅ Fetched 2 rows - __SPLIT__
2026-07-06 11:22:47,745 - [124697] - src.utils.log - INFO - Size of Transaction: 3 - __SPLIT__
2026-07-06 11:22:47,823 - [124697] - src.utils.log - INFO - 📥 Inserting into Billing.Transaction (skip triggers): 3 rows in batches of 25000 (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:48,308 - [124697] - src.utils.log - INFO - 📤 Inserting batch 1/1 (0 to 3) into Billing.Transaction (triggers skipped) - __SPLIT__
2026-07-06 11:22:49,351 - [124697] - src.utils.log - INFO - ✅ All 3 rows inserted successfully into Billing.Transaction in 1 batches (triggers skipped) - __SPLIT__
2026-07-06 11:22:49,549 - [124697] - src.utils.log - INFO - 🔄 Triggers re-enabled for session - __SPLIT__
2026-07-06 11:22:49,627 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT TransactionId, ModifiedBy, TransactionDate as InvoiceDate from Billing.[Transaction] t WHERE t.ModifiedBy in (12345678910, 12345678911, 12345678912)  and t.CompanyId = 133 AND 
        t.TransactionType ='Invoice' AND t.CreatedDate = '2026-07-06 07:22:47.740';... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:50,118 - [124697] - src.utils.log - INFO - ✅ Fetched 3 rows - __SPLIT__
2026-07-06 11:22:50,197 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT * from ServiceCore.ServiceSetupSubWorkOrder ssswo WHERE 
     ssswo.ServiceSetupId  in (150620, 150636);... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:50,541 - [124697] - src.utils.log - INFO - ✅ Fetched 0 rows - __SPLIT__
2026-07-06 11:22:50,624 - [124697] - src.utils.log - INFO - 📝 Executing: 
                    UPDATE Billing.[Transaction]
                    SET ModifiedBy = NULL
                    WHERE ModifiedBy IN (12345678910,12345678911,12345678912)
                    AND CreatedDate = '2026-07-06 07:22:47.740';
                ... (Thread: ThreadPoolExecutor-10_0) - __SPLIT__
2026-07-06 11:22:51,064 - [124697] - src.utils.log - INFO - ✅ Command executed successfully - __SPLIT__
2026-07-06 11:22:51,145 - [124697] - src.utils.log - INFO - Checking if all rows exist in parent table or not - __SPLIT__
2026-07-06 11:22:51,213 - [124697] - src.utils.log - INFO - 📥 Inserting into Billing.Invoice: 3 rows in batches of 25000 (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:51,557 - [124697] - src.utils.log - INFO - 📤 Inserting batch 1/1 (0 to 3) into Billing.Invoice - __SPLIT__
2026-07-06 11:22:52,585 - [124697] - src.utils.log - INFO - ✅ All 3 rows inserted successfully into Billing.Invoice in 1 batches - __SPLIT__
2026-07-06 11:22:52,659 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT InvoiceId, WorkOrderNo FROM Billing.Invoice i WHERE i.WorkOrderNo in ('1427242', '1427246', '1427244')... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:53,685 - [124697] - src.utils.log - INFO - ✅ Fetched 3 rows - __SPLIT__
2026-07-06 11:22:53,767 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT sss.ServiceSetupId, sss.NonStdSoldServiceId as SoldServiceNonStandardId, sss.Qty as Quantity, 
        sss.Price as Rate, sss.IsTaxable, sm.Name as  NonStandardServiceName, sm.Description , sm.ServiceMasterId as ServiceId
        FROM ServiceCore.ServiceSetupServices sss join ServiceCore.ServiceMaster sm on sm.ServiceMasterId = sss.ServiceId 
        where ServiceSetupId = 150620 and sss.IsDeleted =0;... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:54,107 - [124697] - src.utils.log - INFO - ✅ Fetched 1 rows - __SPLIT__
2026-07-06 11:22:54,177 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT sss.ServiceSetupId, sss.NonStdSoldServiceId as SoldServiceNonStandardId, sss.Qty as Quantity, 
        sss.Price as Rate, sss.IsTaxable, sm.Name as  NonStandardServiceName, sm.Description , sm.ServiceMasterId as ServiceId
        FROM ServiceCore.ServiceSetupInitialServices sss join ServiceCore.ServiceMaster sm on sm.ServiceMasterId = sss.ServiceId 
        where ServiceSetupId = 150620 and sss.IsDeleted =0;... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:54,517 - [124697] - src.utils.log - INFO - ✅ Fetched 1 rows - __SPLIT__
2026-07-06 11:22:54,586 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT sss.ServiceSetupId, sss.NonStdSoldServiceId as SoldServiceNonStandardId, sss.Qty as Quantity, 
        sss.Price as Rate, sss.IsTaxable, sm.servicename as  NonStandardServiceName, sm.Description , sss.ServiceId
        FROM ServiceCore.ServiceSetupServices sss join ServiceCore.SoldServiceNonStandard sm on sm.SoldServiceNonStandardId = sss.NonStdSoldServiceId 
        where ServiceSetupId = 150620  and sss.IsDeleted =0;  ... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:54,938 - [124697] - src.utils.log - INFO - ✅ Fetched 0 rows - __SPLIT__
2026-07-06 11:22:55,013 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT sss.ServiceSetupId, sss.NonStdSoldServiceId as SoldServiceNonStandardId, sss.Qty as Quantity, 
        sss.Price as Rate, sss.IsTaxable, sm.servicename as  NonStandardServiceName, sm.Description , sss.ServiceId
        FROM ServiceCore.ServiceSetupInitialServices sss join ServiceCore.SoldServiceNonStandard sm on sm.SoldServiceNonStandardId = sss.NonStdSoldServiceId 
        where ServiceSetupId = 150620  and sss.IsDeleted =0;  ... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:55,351 - [124697] - src.utils.log - INFO - ✅ Fetched 0 rows - __SPLIT__
2026-07-06 11:22:55,437 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT * from ServiceCore.ServiceSetupSubWorkOrder ssswo WHERE 
     ssswo.ServiceSetupId  = 150620;... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:55,814 - [124697] - src.utils.log - INFO - ✅ Fetched 0 rows - __SPLIT__
2026-07-06 11:22:55,885 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT IsInitialSetupDiscount as IsInitial, DiscountSetupId, 
        AppliedDiscountAmt as AppliedDiscountAmount,IsActive ,ServiceSetupId  from 
        ServiceCore.ServiceSetupAppliedDiscount ssad WHERE ssad.ServiceSetupId = 150620;... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:56,229 - [124697] - src.utils.log - INFO - ✅ Fetched 0 rows - __SPLIT__
2026-07-06 11:22:56,296 - [124697] - src.utils.log - INFO - 🔍 Fetching data: SELECT IsInitialSetupDiscount as IsInitial, DiscountSetupId,IsActive,DiscountAmount,
        IsDiscountPercent,DiscountPercent,DiscountDescription , ServiceSetupId from 
        ServiceCore.ServiceSetupAppliedDiscount ssad WHERE ssad.ServiceSetupId = 150620;... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:56,632 - [124697] - src.utils.log - INFO - ✅ Fetched 0 rows - __SPLIT__
2026-07-06 11:22:56,696 - [124697] - src.utils.log - INFO - Sequential Insertion in invoice tables begin - __SPLIT__
2026-07-06 11:22:56,762 - [124697] - src.utils.log - INFO - 📥 Empty dataframe of Billing.AccountDiscountSetup: - __SPLIT__
2026-07-06 11:22:56,823 - [124697] - src.utils.log - INFO - Checking if all rows exist in parent table or not - __SPLIT__
2026-07-06 11:22:56,891 - [124697] - src.utils.log - INFO - 📥 Inserting into Billing.InvoiceCharges: 3 rows in batches of 25000 (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:57,234 - [124697] - src.utils.log - INFO - 📤 Inserting batch 1/1 (0 to 3) into Billing.InvoiceCharges - __SPLIT__
2026-07-06 11:22:58,251 - [124697] - src.utils.log - INFO - ✅ All 3 rows inserted successfully into Billing.InvoiceCharges in 1 batches - __SPLIT__
2026-07-06 11:22:58,316 - [124697] - src.utils.log - INFO - 📥 Empty dataframe of Billing.DiscountApplied: - __SPLIT__
2026-07-06 11:22:58,369 - [124697] - src.utils.log - INFO - Invoice Publish Done - __SPLIT__
2026-07-06 11:22:58,433 - [124697] - src.utils.log - INFO - Updating Next GenerationDate - __SPLIT__
2026-07-06 11:22:58,508 - [124697] - src.utils.log - INFO - 🔍 Fetching data: 
            SELECT ServiceSetupId, MAX(NextWorkOrderGenerationDate) AS MaxNextWorkOrderGeneration
            FROM ServiceCore.WorkOrderSkipMonthAutoGeneration
            WHERE GenerateWorkOrderHistoryId = 124697
            GROUP BY ServiceSetupId;
        ... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:22:58,838 - [124697] - src.utils.log - INFO - ✅ Fetched 0 rows - __SPLIT__
2026-07-06 11:22:58,907 - [124697] - src.utils.log - INFO - 🔄 Updating next gen date sequentially: inside update_next_workorder_generation - __SPLIT__
2026-07-06 11:22:59,104 - [124697] - src.utils.log - INFO - 🛠 Creating temp table #tbl_c4198039d4 - __SPLIT__
2026-07-06 11:22:59,434 - [124697] - src.utils.log - INFO - 📌 Bulk inserting 2 rows into #tbl_c4198039d4 - __SPLIT__
2026-07-06 11:22:59,892 - [124697] - src.utils.log - INFO - 🔁 Running MERGE update to apply changes - __SPLIT__
2026-07-06 11:23:00,178 - [124697] - src.utils.log - INFO - ✔ SQL reported affected rows: 2 - __SPLIT__
2026-07-06 11:23:00,388 - [124697] - src.utils.log - INFO - 🔍 Verified successfully updated 2 rows via #tbl_c4198039d4 - __SPLIT__
2026-07-06 11:23:00,458 - [124697] - src.utils.log - INFO - 🎉 Successfully updated NextGenerationDate using temp table #tbl_c4198039d4 - __SPLIT__
2026-07-06 11:23:00,535 - [124697] - src.utils.log - INFO - 🗑️ Deleting records: 
                DELETE FROM ServiceCore.WorkOrderSkipMonthAutoGeneration
                WHERE GenerateWorkOrderHistoryId = 124697
               (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:00,873 - [124697] - src.utils.log - INFO - ✅ Records deleted successfully - __SPLIT__
2026-07-06 11:23:00,956 - [124697] - src.utils.log - INFO - Sequential deletion from temp tables begin - __SPLIT__
2026-07-06 11:23:01,026 - [124697] - src.utils.log - INFO - 🗑️ Deleting records: DELETE FROM ServiceCore.WorkOrderAutoGenerationServices WHERE WorkOrderAutoGenerationId in (3681142, 3681143, 3681144, 3681145, 3681146)   (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:01,502 - [124697] - src.utils.log - INFO - ✅ Records deleted successfully - __SPLIT__
2026-07-06 11:23:01,580 - [124697] - src.utils.log - INFO - 🗑️ Deleting records: DELETE FROM ServiceCore.WorkOrderAutoGenerationCrews WHERE WorkOrderAutoGenerationId in (3681142, 3681143, 3681144, 3681145, 3681146)   (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:02,003 - [124697] - src.utils.log - INFO - ✅ Records deleted successfully - __SPLIT__
2026-07-06 11:23:02,075 - [124697] - src.utils.log - INFO - 🗑️ Deleting records: DELETE FROM ServiceCore.WorkOrderAutoGenerationSalesPersonCommission WHERE WorkOrderAutoGenerationId in (3681142, 3681143, 3681144, 3681145, 3681146)   (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:02,418 - [124697] - src.utils.log - INFO - ✅ Records deleted successfully - __SPLIT__
2026-07-06 11:23:02,498 - [124697] - src.utils.log - INFO - 🗑️ Deleting records: DELETE FROM ServiceCore.WorkOrderAutoGenerationAppliedDiscount WHERE WorkOrderAutoGenerationId in (3681142, 3681143, 3681144, 3681145, 3681146)   (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:02,918 - [124697] - src.utils.log - INFO - ✅ Records deleted successfully - __SPLIT__
2026-07-06 11:23:02,991 - [124697] - src.utils.log - INFO - 🗑️ Deleting records: DELETE FROM ServiceCore.SetupAutoGenerationSourceMapping WHERE WorkOrderAutoGenerationId in (3681142, 3681143, 3681144, 3681145, 3681146)   (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:03,337 - [124697] - src.utils.log - INFO - ✅ Records deleted successfully - __SPLIT__
2026-07-06 11:23:03,408 - [124697] - src.utils.log - INFO - 🗑️ Deleting records: DELETE FROM ServiceCore.SubWorkOrderAutoGeneration WHERE WorkOrderAutoGenerationId in (3681142, 3681143, 3681144, 3681145, 3681146)   (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:03,748 - [124697] - src.utils.log - INFO - ✅ Records deleted successfully - __SPLIT__
2026-07-06 11:23:03,821 - [124697] - src.utils.log - INFO - 🗑️ Deleting records: DELETE FROM ServiceCore.WorkOrderAutoGenerationCommissionAdjustment WHERE WorkOrderAutoGenerationId in (3681142, 3681143, 3681144, 3681145, 3681146)   (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:04,156 - [124697] - src.utils.log - INFO - ✅ Records deleted successfully - __SPLIT__
2026-07-06 11:23:04,271 - [124697] - src.utils.log - INFO - 🗑️ Deleting records: DELETE FROM ServiceCore.WorkOrderAutoGeneration WHERE WorkOrderAutoGenerationId in (3681142, 3681143, 3681144, 3681145, 3681146)   (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:04,811 - [124697] - src.utils.log - INFO - ✅ Records deleted successfully - __SPLIT__
2026-07-06 11:23:04,875 - [124697] - src.utils.log - INFO - Work order published ids: (3681142, 3681143, 3681144, 3681145, 3681146) - __SPLIT__
2026-07-06 11:23:04,929 - [124697] - src.utils.log - INFO - Time took to perform operation in publishing [124697]: 42.28 - __SPLIT__
2026-07-06 11:23:04,997 - [124697] - src.utils.log - INFO - Publish Completed for GenerateWorkOrderHistoryId: [124697] - __SPLIT__
2026-07-06 11:23:05,061 - [124697] - src.utils.log - INFO - 📝 Executing: UPDATE ServiceCore.GenerateWorkOrderHistory SET PublishStatus = 'Completed', 
                        PublishStatusDateTime = '2026-07-06 07:23:04.875' WHERE CompanyId = 133 AND 
                        GenerateWorkOrderHistoryId = 124697;... (Thread: AnyIO worker thread) - __SPLIT__
2026-07-06 11:23:05,393 - [124697] - src.utils.log - INFO - ✅ Command executed successfully - __SPLIT__