2025-10-18T21:50:03.903+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@7a37282e is alive
2025-10-18T21:50:06.727+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@600b68f9 is alive
2025-10-18T21:50:09.532+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] o.s.security.web.FilterChainProxy        : Securing POST /api/voip/telnyx/texml-response
2025-10-18T21:50:09.533+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] o.s.s.w.a.AnonymousAuthenticationFilter  : Set SecurityContextHolder to anonymous SecurityContext
2025-10-18T21:50:09.533+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] o.s.security.web.FilterChainProxy        : Secured POST /api/voip/telnyx/texml-response
2025-10-18T21:50:09.534+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] o.s.web.servlet.DispatcherServlet        : POST "/api/voip/telnyx/texml-response", parameters={}
2025-10-18T21:50:09.534+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.saas.voip.controller.TelnyxTeXMLController#handleTeXMLRequest(HttpServletRequest, String, String, String, String)
2025-10-18T21:50:09.534+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
2025-10-18T21:50:09.537+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-3] c.s.v.controller.TelnyxTeXMLController   : === TELNYX TeXML REQUEST ===
2025-10-18T21:50:09.537+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-3] c.s.v.controller.TelnyxTeXMLController   : 📞 From: null, To: null, CallSid: null, Status: null
2025-10-18T21:50:09.537+01:00  WARN 89734 --- [saas-multitenant-api] [nio-7001-exec-3] c.s.v.controller.TelnyxTeXMLController   : ⚠️ No VoIP configuration found for tenant: null
2025-10-18T21:50:09.538+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] m.m.a.RequestResponseBodyMethodProcessor : Using 'application/xml', given [*/*] and supported [application/xml]
2025-10-18T21:50:09.538+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] m.m.a.RequestResponseBodyMethodProcessor : Writing ["<?xml version="1.0" encoding="UTF-8"?><EOL><Response><EOL>  <Say language="fr-FR">Configuration VoIP non tro (truncated)..."]
2025-10-18T21:50:09.539+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
2025-10-18T21:50:09.539+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-3] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2025-10-18T21:50:12.769+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@73973e77 is alive
2025-10-18T21:50:20.374+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=10/10, idle=10/10, active=0, waiting=0)
2025-10-18T21:50:20.375+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Fill pool skipped, pool has sufficient level or currently being filled.
2025-10-18T21:50:29.923+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@7264e2bd is alive
2025-10-18T21:50:30.091+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@76aa6fc1 is alive
2025-10-18T21:50:36.843+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@1551f18b is alive
2025-10-18T21:50:37.024+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@31555bef is alive
2025-10-18T21:50:37.459+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@49ce5b7c is alive
2025-10-18T21:50:39.428+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.security.web.FilterChainProxy        : Securing POST /api/voip/telnyx/texml-response
2025-10-18T21:50:39.429+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.s.w.a.AnonymousAuthenticationFilter  : Set SecurityContextHolder to anonymous SecurityContext
2025-10-18T21:50:39.430+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.security.web.FilterChainProxy        : Secured POST /api/voip/telnyx/texml-response
2025-10-18T21:50:39.430+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.web.servlet.DispatcherServlet        : POST "/api/voip/telnyx/texml-response", parameters={masked}
2025-10-18T21:50:39.430+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.saas.voip.controller.TelnyxTeXMLController#handleTeXMLRequest(HttpServletRequest, String, String, String, String)
2025-10-18T21:50:39.430+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
2025-10-18T21:50:39.431+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.v.controller.TelnyxTeXMLController   : === TELNYX TeXML REQUEST ===
2025-10-18T21:50:39.432+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.v.controller.TelnyxTeXMLController   : 📞 From: +212661979197, To: +18066983980, CallSid: v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw, Status: null
2025-10-18T21:50:39.433+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.ast.create         : Created new SQL alias : pn1_0
2025-10-18T21:50:39.433+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.ast.create         : Registration of TableGroup [StandardTableGroup(com.saas.admin.entity.PhoneNumber(62))] with identifierForTableGroup [com.saas.admin.entity.PhoneNumber] for NavigablePath [com.saas.admin.entity.PhoneNumber] 
2025-10-18T21:50:39.433+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmParameter : org.hibernate.query.sqm.tree.expression.SqmJpaCriteriaParameterWrapper@18e0a1fc
2025-10-18T21:50:39.433+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmPath : SqmBasicValuedSimplePath(com.saas.admin.entity.PhoneNumber(62).phoneNumber) 
2025-10-18T21:50:39.433+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.results.graph.AST      : DomainResult Graph:
 \-EntityResultImpl [com.saas.admin.entity.PhoneNumber(62)]
 |  +-BasicFetch [com.saas.admin.entity.PhoneNumber(62).createdAt]
 |  +-BasicFetch [com.saas.admin.entity.PhoneNumber(62).description]
 |  +-BasicFetch [com.saas.admin.entity.PhoneNumber(62).friendlyName]
 |  +-BasicFetch [com.saas.admin.entity.PhoneNumber(62).isActive]
 |  +-BasicFetch [com.saas.admin.entity.PhoneNumber(62).phoneNumber]
 |  +-BasicFetch [com.saas.admin.entity.PhoneNumber(62).provider]
 |  +-BasicFetch [com.saas.admin.entity.PhoneNumber(62).tenantId]
 |  \-BasicFetch [com.saas.admin.entity.PhoneNumber(62).updatedAt]

2025-10-18T21:50:39.433+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.ast.tree           : SQL AST Tree:
    SelectStatement {
      FromClause {
        StandardTableGroup (pn1 : com.saas.admin.entity.PhoneNumber(62)) {
          primaryTableReference : phone_numbers as pn1_0
        }
      }
    }

2025-10-18T21:50:39.434+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.exec               : Skipping reading Query result cache data: cache-enabled = false, cache-mode = NORMAL
2025-10-18T21:50:39.434+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.SQL                        : 
    select
        pn1_0.id,
        pn1_0.created_at,
        pn1_0.description,
        pn1_0.friendly_name,
        pn1_0.is_active,
        pn1_0.phone_number,
        pn1_0.provider,
        pn1_0.tenant_id,
        pn1_0.updated_at 
    from
        phone_numbers pn1_0 
    where
        pn1_0.phone_number=?
Hibernate: 
    select
        pn1_0.id,
        pn1_0.created_at,
        pn1_0.description,
        pn1_0.friendly_name,
        pn1_0.is_active,
        pn1_0.phone_number,
        pn1_0.provider,
        pn1_0.tenant_id,
        pn1_0.updated_at 
    from
        phone_numbers pn1_0 
    where
        pn1_0.phone_number=?
2025-10-18T21:50:39.438+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.results                : Initializer list:
	  com.saas.admin.entity.PhoneNumber(62) -> EntityJoinedFetchInitializer(com.saas.admin.entity.PhoneNumber(62))@1852713003 (SingleTableEntityPersister(com.saas.admin.entity.PhoneNumber))

2025-10-18T21:50:39.442+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.v.controller.TelnyxTeXMLController   : ✅ Identified Tenant: 3a3de642-6da5-4bd0-8fb8-b933155dfd62 for Telnyx number: +18066983980
2025-10-18T21:50:39.443+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.ast.create         : Created new SQL alias : t1_0
2025-10-18T21:50:39.443+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.ast.create         : Registration of TableGroup [StandardTableGroup(com.saas.admin.entity.Tenant(26))] with identifierForTableGroup [com.saas.admin.entity.Tenant] for NavigablePath [com.saas.admin.entity.Tenant] 
2025-10-18T21:50:39.443+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmParameter : org.hibernate.query.sqm.tree.expression.SqmJpaCriteriaParameterWrapper@6e87517e
2025-10-18T21:50:39.443+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmPath : SqmBasicValuedSimplePath(com.saas.admin.entity.Tenant(26).tenantId) 
2025-10-18T21:50:39.443+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.results.graph.AST      : DomainResult Graph:
 \-EntityResultImpl [com.saas.admin.entity.Tenant(26)]
 |  +-BasicFetch [com.saas.admin.entity.Tenant(26).createdAt]
 |  +-BasicFetch [com.saas.admin.entity.Tenant(26).schemaName]
 |  +-BasicFetch [com.saas.admin.entity.Tenant(26).status]
 |  +-BasicFetch [com.saas.admin.entity.Tenant(26).tenantId]
 |  +-BasicFetch [com.saas.admin.entity.Tenant(26).tenantName]
 |  \-BasicFetch [com.saas.admin.entity.Tenant(26).updatedAt]

2025-10-18T21:50:39.443+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.ast.tree           : SQL AST Tree:
    SelectStatement {
      FromClause {
        StandardTableGroup (t1 : com.saas.admin.entity.Tenant(26)) {
          primaryTableReference : tenants as t1_0
        }
      }
    }

2025-10-18T21:50:39.443+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.exec               : Skipping reading Query result cache data: cache-enabled = false, cache-mode = NORMAL
2025-10-18T21:50:39.444+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.SQL                        : 
    select
        t1_0.id,
        t1_0.created_at,
        t1_0.schema_name,
        t1_0.status,
        t1_0.tenant_id,
        t1_0.tenant_name,
        t1_0.updated_at 
    from
        tenants t1_0 
    where
        t1_0.tenant_id=?
Hibernate: 
    select
        t1_0.id,
        t1_0.created_at,
        t1_0.schema_name,
        t1_0.status,
        t1_0.tenant_id,
        t1_0.tenant_name,
        t1_0.updated_at 
    from
        tenants t1_0 
    where
        t1_0.tenant_id=?
2025-10-18T21:50:39.445+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.results                : Initializer list:
	  com.saas.admin.entity.Tenant(26) -> EntityJoinedFetchInitializer(com.saas.admin.entity.Tenant(26))@32120970 (SingleTableEntityPersister(com.saas.admin.entity.Tenant))

2025-10-18T21:50:39.446+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.v.controller.TelnyxTeXMLController   : 📊 Using schema: tenant_clinique_la_rive1_bleue1
2025-10-18T21:50:39.446+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1809351049<open>)] for JPA transaction
2025-10-18T21:50:39.446+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [com.saas.tenant.service.InboundCallService.saveCallData]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2025-10-18T21:50:39.446+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.e.t.internal.TransactionImpl         : On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2025-10-18T21:50:39.447+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.e.t.internal.TransactionImpl         : begin
2025-10-18T21:50:39.447+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@3be61208]
2025-10-18T21:50:39.447+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1809351049<open>)] for JPA transaction
2025-10-18T21:50:39.447+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2025-10-18T21:50:39.447+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.j.internal.PersistenceUnitUtilImpl   : jakarta.persistence.PersistenceUnitUtil.getIdentifier is only intended to work with enhanced entities (although Hibernate also adapts this support to its proxies); however the passed entity was not enhanced (nor a proxy).. may not be able to read identifier
2025-10-18T21:50:39.448+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.engine.spi.ActionQueue     : Executing identity-insert immediately
2025-10-18T21:50:39.448+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.SQL                        : 
    insert 
    into
        inbound_call_data
        (account_sid, api_version, call_sid, call_status, call_token, called, called_city, called_country, called_state, called_zip, caller, caller_city, caller_country, caller_state, caller_zip, created_at, direction, duration, end_time, forwarded_from, from_city, from_country, from_number, from_state, from_zip, parent_call_sid, recording_sid, recording_url, start_time, stir_verstat, to_city, to_country, to_number, to_state, to_zip, updated_at) 
    values
        (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
Hibernate: 
    insert 
    into
        inbound_call_data
        (account_sid, api_version, call_sid, call_status, call_token, called, called_city, called_country, called_state, called_zip, caller, caller_city, caller_country, caller_state, caller_zip, created_at, direction, duration, end_time, forwarded_from, from_city, from_country, from_number, from_state, from_zip, parent_call_sid, recording_sid, recording_url, start_time, stir_verstat, to_city, to_country, to_number, to_state, to_zip, updated_at) 
    values
        (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2025-10-18T21:50:39.451+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.results                : Initializer list is empty
2025-10-18T21:50:39.451+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.id.IdentifierGeneratorHelper         : Extracted generated values [com.saas.tenant.entity.InboundCallData]: [Ljava.lang.Object;@582fe3a0
2025-10-18T21:50:39.451+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.tenant.service.InboundCallService    : 💾 Call data saved - CallSid: v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw, From: +212661979197, To: +18066983980
2025-10-18T21:50:39.451+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2025-10-18T21:50:39.451+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(1809351049<open>)]
2025-10-18T21:50:39.451+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.e.t.internal.TransactionImpl         : committing
2025-10-18T21:50:39.451+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2025-10-18T21:50:39.451+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2025-10-18T21:50:39.452+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
2025-10-18T21:50:39.452+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2025-10-18T21:50:39.452+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.hibernate.internal.util.EntityPrinter  : Listing entities:
2025-10-18T21:50:39.452+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.hibernate.internal.util.EntityPrinter  : com.saas.admin.entity.PhoneNumber{createdAt=2025-10-18T21:37:17.027607, phoneNumber=+18066983980, provider=TELNYX, tenantId=3a3de642-6da5-4bd0-8fb8-b933155dfd62, description=Main clinic line, id=1, isActive=true, friendlyName=Clinique La Rive1 Bleue1, updatedAt=2025-10-18T21:37:17.027623}
2025-10-18T21:50:39.452+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.hibernate.internal.util.EntityPrinter  : com.saas.tenant.entity.InboundCallData{callerCountry=null, called=null, fromZip=null, stirVerstat=null, parentCallSid=null, callerState=null, duration=null, createdAt=2025-10-18T21:50:39.448395, toState=null, apiVersion=null, recordingSid=null, callStatus=initiated, calledZip=null, startTime=2025-10-18T21:50:39.446774, id=1, direction=inbound, updatedAt=2025-10-18T21:50:39.448407, callerCity=null, fromState=null, callSid=v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw, fromCountry=null, calledCity=null, toCity=null, calledCountry=null, callerZip=null, toCountry=null, calledState=null, fromNumber=+212661979197, toZip=null, callToken=null, caller=null, recordingUrl=null, endTime=null, forwardedFrom=null, accountSid=null, fromCity=null, toNumber=+18066983980}
2025-10-18T21:50:39.452+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.hibernate.internal.util.EntityPrinter  : com.saas.admin.entity.Tenant{createdAt=2025-10-18T21:02:45.389443, tenantName=Clinique La Rive1 Bleue1, tenantId=3a3de642-6da5-4bd0-8fb8-b933155dfd62, id=2, schemaName=tenant_clinique_la_rive1_bleue1, status=ACTIVE, updatedAt=2025-10-18T21:02:45.389477}
2025-10-18T21:50:39.453+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
2025-10-18T21:50:39.453+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.v.controller.TelnyxTeXMLController   : ✅ Telnyx call data saved to schema: tenant_clinique_la_rive1_bleue1
2025-10-18T21:50:39.453+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1809351049<open>)] for JPA transaction
2025-10-18T21:50:39.453+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [com.saas.shared.service.TenantVoipConfigRuntimeService.resolveVoipConfig]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
2025-10-18T21:50:39.453+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.jdbc.datasource.DataSourceUtils      : Setting JDBC Connection [HikariProxyConnection@279943133 wrapping com.mysql.cj.jdbc.ConnectionImpl@73973e77] read-only
2025-10-18T21:50:39.453+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.e.t.internal.TransactionImpl         : begin
2025-10-18T21:50:39.454+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@37ba548b]
2025-10-18T21:50:39.454+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.s.s.TenantVoipConfigRuntimeService   : 🔍 Resolving VoIP config for tenant: 3a3de642-6da5-4bd0-8fb8-b933155dfd62, provider: TELNYX
2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.ast.create         : Created new SQL alias : tvc1_0
2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.ast.create         : Registration of TableGroup [StandardTableGroup(com.saas.admin.entity.TenantVoipConfig(88))] with identifierForTableGroup [com.saas.admin.entity.TenantVoipConfig] for NavigablePath [com.saas.admin.entity.TenantVoipConfig] 
2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmParameter : org.hibernate.query.sqm.tree.expression.SqmJpaCriteriaParameterWrapper@40cdef57
2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmPath : SqmBasicValuedSimplePath(com.saas.admin.entity.TenantVoipConfig(88).tenantId) 
2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmParameter : org.hibernate.query.sqm.tree.expression.SqmJpaCriteriaParameterWrapper@f09c02
2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmPath : SqmBasicValuedSimplePath(com.saas.admin.entity.TenantVoipConfig(88).provider) 
2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmParameter : org.hibernate.query.sqm.tree.expression.SqmJpaCriteriaParameterWrapper@5b05ccdf
2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.q.sqm.sql.BaseSqmToSqlAstConverter   : Determining mapping-model type for SqmPath : SqmBasicValuedSimplePath(com.saas.admin.entity.TenantVoipConfig(88).isActive) 
2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.results.graph.AST      : DomainResult Graph:
 \-EntityResultImpl [com.saas.admin.entity.TenantVoipConfig(88)]
 |  +-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).aiAssistantId]
 |  +-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).aiType]
 |  +-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).createdAt]
 |  +-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).isActive]
 |  +-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).messagingProfileId]
 |  +-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).metadata]
 |  +-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).provider]
 |  +-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).streamUrl]
 |  +-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).tenantId]
 |  \-BasicFetch [com.saas.admin.entity.TenantVoipConfig(88).updatedAt]

2025-10-18T21:50:39.455+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.ast.tree           : SQL AST Tree:
    SelectStatement {
      FromClause {
        StandardTableGroup (tvc1 : com.saas.admin.entity.TenantVoipConfig(88)) {
          primaryTableReference : tenant_voip_configs as tvc1_0
        }
      }
    }

2025-10-18T21:50:39.456+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.sql.exec               : Skipping reading Query result cache data: cache-enabled = false, cache-mode = NORMAL
2025-10-18T21:50:39.456+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.SQL                        : 
    select
        tvc1_0.id,
        tvc1_0.ai_assistant_id,
        tvc1_0.ai_type,
        tvc1_0.created_at,
        tvc1_0.is_active,
        tvc1_0.messaging_profile_id,
        tvc1_0.metadata,
        tvc1_0.provider,
        tvc1_0.stream_url,
        tvc1_0.tenant_id,
        tvc1_0.updated_at 
    from
        tenant_voip_configs tvc1_0 
    where
        tvc1_0.tenant_id=? 
        and tvc1_0.provider=? 
        and tvc1_0.is_active=?
Hibernate: 
    select
        tvc1_0.id,
        tvc1_0.ai_assistant_id,
        tvc1_0.ai_type,
        tvc1_0.created_at,
        tvc1_0.is_active,
        tvc1_0.messaging_profile_id,
        tvc1_0.metadata,
        tvc1_0.provider,
        tvc1_0.stream_url,
        tvc1_0.tenant_id,
        tvc1_0.updated_at 
    from
        tenant_voip_configs tvc1_0 
    where
        tvc1_0.tenant_id=? 
        and tvc1_0.provider=? 
        and tvc1_0.is_active=?
2025-10-18T21:50:39.457+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] org.hibernate.orm.results                : Initializer list:
	  com.saas.admin.entity.TenantVoipConfig(88) -> EntityJoinedFetchInitializer(com.saas.admin.entity.TenantVoipConfig(88))@1426151074 (SingleTableEntityPersister(com.saas.admin.entity.TenantVoipConfig))

2025-10-18T21:50:39.458+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.s.s.TenantVoipConfigRuntimeService   : ✅ VoIP config found in database (active)
2025-10-18T21:50:39.459+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2025-10-18T21:50:39.459+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(1809351049<open>)]
2025-10-18T21:50:39.459+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.h.e.t.internal.TransactionImpl         : committing
2025-10-18T21:50:39.459+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.jdbc.datasource.DataSourceUtils      : Resetting read-only flag of JDBC Connection [HikariProxyConnection@279943133 wrapping com.mysql.cj.jdbc.ConnectionImpl@73973e77]
2025-10-18T21:50:39.460+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
2025-10-18T21:50:39.460+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.v.controller.TelnyxTeXMLController   : 🔧 VoIP Config - Type: TELNYX_NATIVE_AI, AssistantID: assistant-265ff822-c3e7-43ca-b9f3-02d3ae189e7d, StreamURL: wss://benedictory-provocative-lauralee.ngrok-free.dev/stream, Source: DATABASE
2025-10-18T21:50:39.460+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.v.controller.TelnyxTeXMLController   : 🤖 Starting Telnyx Native AI Assistant: assistant-265ff822-c3e7-43ca-b9f3-02d3ae189e7d
2025-10-18T21:50:39.460+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-4] c.s.v.controller.TelnyxTeXMLController   : 📄 TeXML Response:
<?xml version="1.0" encoding="UTF-8"?>
<Response>
  <!-- Start Telnyx Native AI Assistant -->
  <Start>
    <TelnyxAI assistantId="assistant-265ff822-c3e7-43ca-b9f3-02d3ae189e7d"/>
  </Start>
</Response>
2025-10-18T21:50:39.460+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] m.m.a.RequestResponseBodyMethodProcessor : Using 'application/xml', given [*/*] and supported [application/xml]
2025-10-18T21:50:39.460+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] m.m.a.RequestResponseBodyMethodProcessor : Writing ["<?xml version="1.0" encoding="UTF-8"?><EOL><Response><EOL>  <!-- Start Telnyx Native AI Assistant --><EOL>  <Sta (truncated)..."]
2025-10-18T21:50:39.461+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
2025-10-18T21:50:39.461+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-4] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2025-10-18T21:50:46.668+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@649c8572 is alive
2025-10-18T21:50:49.355+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@2a51b5db is alive
2025-10-18T21:50:50.380+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=10/10, idle=10/10, active=0, waiting=0)
2025-10-18T21:50:50.380+01:00 DEBUG 89734 --- [saas-multitenant-api] [l-1:housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Fill pool skipped, pool has sufficient level or currently being filled.
2025-10-18T21:51:01.679+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] o.s.security.web.FilterChainProxy        : Securing POST /api/voip/telnyx/ai/conversation-event
2025-10-18T21:51:01.681+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] o.s.s.w.a.AnonymousAuthenticationFilter  : Set SecurityContextHolder to anonymous SecurityContext
2025-10-18T21:51:01.682+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] o.s.security.web.FilterChainProxy        : Secured POST /api/voip/telnyx/ai/conversation-event
2025-10-18T21:51:01.683+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] o.s.web.servlet.DispatcherServlet        : POST "/api/voip/telnyx/ai/conversation-event", parameters={masked}
2025-10-18T21:51:01.683+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.saas.voip.controller.TelnyxEventController#handleConversationEvent(HttpServletRequest, Map)
2025-10-18T21:51:01.683+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
2025-10-18T21:51:01.687+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-6] c.s.v.controller.TelnyxEventController   : === TELNYX AI CONVERSATION EVENT ===
2025-10-18T21:51:01.687+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-6] c.s.v.controller.TelnyxEventController   : 📥 Content-Type: application/x-www-form-urlencoded
2025-10-18T21:51:01.687+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-6] c.s.v.controller.TelnyxEventController   : 📥 All parameters: {AccountSid=24b8c68c-c52a-4dd2-859c-22f1d2e62203, AnsweredTime=2025-10-18T20:50:39.857869Z, CallControlId=v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw, CallDuration=22, CallLegId=1a7fbd28-ac64-11f0-bcdb-02420aef50a0, CallQualityStats={"inbound":{"jitter_max_variance":"18.15","jitter_packet_count":"0","mos":"4.50","packet_count":"1079","skip_packet_count":"5"},"outbound":{"packet_count":"0","skip_packet_count":"0"}}, CallSessionId=1a7fb2e2-ac64-11f0-b5ee-02420aef50a0, CallSid=v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw, CallSidLegacy=v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw, CallStatus=completed, CallbackSource=call-progress-events, CallingPartyType=pstn, ConnectionId=2806750933822736154, EndTime=2025-10-18T20:51:01.517864Z, From=+212661979197, FromSipUri=+212661979197@208.69.82.78:5060, HangupCause=normal_clearing, HangupSource=caller, OccurredAt=2025-10-18T20:51:01.517864Z, OrganizationId=24b8c68c-c52a-4dd2-859c-22f1d2e62203, SequenceNumber=0, SipHangupCause=200, StartTime=2025-10-18T20:50:39.857869Z, Timestamp=2025-10-18 20:51:01.690715Z, To=+18066983980, ToSipUri=+18066983980@64.16.250.10:5060, UserId=24b8c68c-c52a-4dd2-859c-22f1d2e62203}
2025-10-18T21:51:01.691+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/yaml, application/xml;charset=UTF-8, text/xml;charset=UTF-8, application/*+xml;charset=UTF-8]
2025-10-18T21:51:01.691+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Writing [{params_count=27, status=received}]
2025-10-18T21:51:01.692+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
2025-10-18T21:51:01.692+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-6] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2025-10-18T21:51:01.957+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] o.s.security.web.FilterChainProxy        : Securing POST /api/voip/telnyx/ai/conversation-event
2025-10-18T21:51:01.957+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] o.s.s.w.a.AnonymousAuthenticationFilter  : Set SecurityContextHolder to anonymous SecurityContext
2025-10-18T21:51:01.958+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] o.s.security.web.FilterChainProxy        : Secured POST /api/voip/telnyx/ai/conversation-event
2025-10-18T21:51:01.958+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] o.s.web.servlet.DispatcherServlet        : POST "/api/voip/telnyx/ai/conversation-event", parameters={masked}
2025-10-18T21:51:01.958+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.saas.voip.controller.TelnyxEventController#handleConversationEvent(HttpServletRequest, Map)
2025-10-18T21:51:01.958+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
2025-10-18T21:51:01.958+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-7] c.s.v.controller.TelnyxEventController   : === TELNYX AI CONVERSATION EVENT ===
2025-10-18T21:51:01.958+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-7] c.s.v.controller.TelnyxEventController   : 📥 Content-Type: application/x-www-form-urlencoded
2025-10-18T21:51:01.958+01:00  INFO 89734 --- [saas-multitenant-api] [nio-7001-exec-7] c.s.v.controller.TelnyxEventController   : 📥 All parameters: {AccountSid=24b8c68c-c52a-4dd2-859c-22f1d2e62203, BilledDurationSeconds[v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw]=60, CallCost[v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw]=0.0055, CallSid=v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw, CallSidLegacy=v3:dIlYQXKHVEzlYSTTRWFW3c9x1cm9vFrybauiWZeuPzde0YFK-kporw, CallbackSource=call-cost-events, CallerId=+212661979197, CallingPartyType=pstn, ConnectionId=2806750933822736154, From=+212661979197, FromSipUri=+212661979197@208.69.82.78:5060, To=+18066983980, ToSipUri=+18066983980@64.16.250.10:5060}
2025-10-18T21:51:01.959+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/yaml, application/xml;charset=UTF-8, text/xml;charset=UTF-8, application/*+xml;charset=UTF-8]
2025-10-18T21:51:01.959+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Writing [{params_count=13, status=received}]
2025-10-18T21:51:01.959+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
2025-10-18T21:51:01.959+01:00 DEBUG 89734 --- [saas-multitenant-api] [nio-7001-exec-7] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
