Hi @jonbendtsen
Thanks for your help and your hints. I conducted some further investigations and, by making minor additions of syslog calls in the source code, tried to trace the individual steps. These added syslog calls and entries have the prefix "debuglog - ".
I ran the syslog in DEBUG mode and created a new contribution for a member. The (partialy) logging results are as follows:
2025-11-17 20:41:06 DEBUG 89.12.34.6 3326321 31151 debuglog - start function subscriptionComplementaryActions
2025-11-17 20:41:06 INFO 89.12.34.6 3326321 31151 subscriptionComplementaryActions subscriptionid=95 option=invoiceonly accountid=-1 datesubscription=1762210800 paymentdate= label=Mitgliedsbeitrag 2025 amount=24 num_chq= autocreatethirdparty=0
2025-11-17 20:41:08 DEBUG 89.12.34.6 3326321 31151 debuglog - start invoice handling
2025-11-17 20:41:08 DEBUG 89.12.34.6 3326321 31151 sql=SELECT [...]
2025-11-17 20:41:08 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, name, label, type, size, elementtype, fieldunique, fieldrequired, param, pos, alwayseditable, perms, langs, list, printable, totalizable, fielddefault, fieldcomputed, entity, enabled, help, aiprompt, css, cssview, csslist FROM llx_extrafields WHERE elementtype = 'societe' ORDER BY pos
2025-11-17 20:41:10 DEBUG 89.12.34.6 3326321 31151 debuglog - create draft invoice
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 debuglog - create invoice
2025-11-17 20:41:12 INFO 89.12.34.6 3326321 31151 Facture::create user=3 date=1763412070
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=SELECT s.rowid, [...] WHERE s.entity IN (1) AND s.rowid = 37
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 Facture::calculate_date_lim_reglement
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=SELECT c.type_cdr, c.nbjour, c.decalage FROM llx_c_payment_term as c WHERE c.rowid=15
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=INSERT INTO llx_facture ( ref, entity, ref_ext, type, subtype, fk_soc, datec, datef, date_pointoftax, note_private, note_public, ref_client, fk_account, module_source, pos_source, fk_fac_rec_source, fk_facture_source, fk_user_author, fk_projet, fk_cond_reglement, fk_mode_reglement, date_lim_reglement, model_pdf, fk_input_reason, situation_cycle_ref, situation_counter, situation_final, fk_incoterms, location_incoterms, fk_multicurrency, multicurrency_code, multicurrency_tx, retained_warranty, retained_warranty_date_limit, retained_warranty_fk_cond_reglement) VALUES ('(PROV)', 1, null, '0', null, 37, '2025-11-17 21:41:12', '2025-11-17 21:41:10', null, null, null, null, 1, null, null, null, null, 3, null, 15, 3, '2026-01-15 00:00:00', null, null, null, null, 0, 0, '', 0, 'EUR', 1, 0, NULL, 0)
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_facture SET ref='(PROV113)' WHERE rowid=113
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 Facture::add_object_linked
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=INSERT INTO llx_element_element (fk_source, sourcetype, fk_target, targettype) VALUES (95, 'subscription', 113, 'facture')
2025-11-17 20:41:12 INFO 89.12.34.6 3326321 31151 There is 0 lines into ->lines as a simple array
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 Facture::update_price
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, [...] WHERE fk_facture = 113 AND product_type <> 9 ORDER by rowid
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 Facture::update_price
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_facture SET total_ht = 0, total_tva = 0, localtax1 = 0, localtax2 = 0, total_ttc = 0, multicurrency_total_ht = 0, multicurrency_total_tva = 0, multicurrency_total_ttc = 0 WHERE rowid = 113
2025-11-17 20:41:12 INFO 89.12.34.6 3326321 31151 Trigger 'ContactRoles' for action 'BILL_CREATE' launched by /var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/core/triggers/interface_90_modSociete_ContactRoles.class.php. id=113
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 Contact::getContactRoles
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=SELECT sc.fk_socpeople [...] tc.element = 'facture' AND sp.entity IN (1) AND tc.active = 1
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 Facture::addline id=113, pu_ht=0, qty=1, txtva=0, txlocaltax1=0, txlocaltax2=0, fk_product=-1, remise_percent=0, date_start=1762210800, date_end=, fk_code_ventilation=0, info_bits=0, fk_remise_except=0, price_base_type=TTC, pu_ttc=24, type=1, fk_unit=, desc=Mitgliedsbeitrag 2025
2025-11-17 20:41:12 INFO 89.12.34.6 3326321 31151 getLocalTaxesFromRate vatrate=0 local=0
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=SELECT t.taux as rate, [...]
2025-11-17 20:41:12 INFO 89.12.34.6 3326321 31151 get_localtax tva=0 local=2 thirdparty_buyer id=/country_code= thirdparty_seller id=0/country_code=DE thirdparty_seller localtax1_assuj=0 thirdparty_seller localtax2_assuj=0
2025-11-17 20:41:12 INFO 89.12.34.6 3326321 31151 Price.lib::calcul_price_total qty=1 pu=24 remise_percent_ligne=0 txtva=0 uselocaltax1_rate=0 uselocaltax2_rate=0 remise_percent_global=0 price_base_type=TTC type=1 progress=100
2025-11-17 20:41:12 INFO 89.12.34.6 3326321 31151 Price.lib::calcul_price_total MAIN_ROUNDING_RULE_TOT= pu=24 qty=1 price_base_type=TTC total_ht=24-total_vat=0-total_ttc=24
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 Facture::line_max
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=SELECT max(rang) FROM llx_facturedet WHERE fk_facture = 113
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 FactureLigne::insert rang=1
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 FactureLigne::insert
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=INSERT INTO llx_facturedet (fk_facture, fk_parent_line, label, description, qty, vat_src_code, tva_tx, localtax1_tx, localtax2_tx, localtax1_type, localtax2_type, fk_product, product_type, remise_percent, subprice, ref_ext, fk_remise_except, date_start, date_end, fk_code_ventilation, rang, special_code, fk_product_fournisseur_price, buy_price_ht, info_bits, total_ht, total_tva, total_ttc, total_localtax1, total_localtax2, situation_percent, fk_prev_id, fk_unit, fk_user_author, fk_user_modif, fk_multicurrency, multicurrency_code, multicurrency_subprice, multicurrency_total_ht, multicurrency_total_tva, multicurrency_total_ttc, batch, fk_warehouse) VALUES (113, null, null, 'Mitgliedsbeitrag 2025', 1, '', 0, 0, 0, '0', '0', null, 1, 0, 24, '', null, '2025-11-04 00:00:00', null, 0, 1, 0, null, 0, '0', 24, 0, 24, 0, 0, 100, null, NULL, 3, 3, 0, 'EUR', 24, 24, 0, 24, '', 0)
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 Facture::update_price
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=SELECT [...] FROM llx_facturedet WHERE fk_facture = 113 AND product_type <> 9 ORDER by rowid
2025-11-17 20:41:12 INFO 89.12.34.6 3326321 31151 Price.lib::calcul_price_total qty=1 pu=24.00000000 remise_percent_ligne=0 txtva=0.0000 uselocaltax1_rate=0 uselocaltax2_rate=0 remise_percent_global=0 price_base_type=HT type=1 progress=100
2025-11-17 20:41:12 INFO 89.12.34.6 3326321 31151 Price.lib::calcul_price_total MAIN_ROUNDING_RULE_TOT= pu=24.00000000 qty=1 price_base_type=HT total_ht=24-total_vat=0-total_ttc=24
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 Facture::update_price
2025-11-17 20:41:12 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_facture SET total_ht = 24, total_tva = 0, localtax1 = 0, localtax2 = 0, total_ttc = 24, multicurrency_total_ht = 24, multicurrency_total_tva = 0, multicurrency_total_ttc = 24 WHERE rowid = 113
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 debuglog - validate invoice
2025-11-17 20:41:14 INFO 89.12.34.6 3326321 31151 Facture::validate user=3, force_number=, idwarehouse=0
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=SELECT s.rowid, [...] s.fk_incoterms = i.rowid WHERE s.entity IN (1) AND s.rowid = 37
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 Facture::fetch_lines
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=SELECT l.rowid, [...] FROM llx_facturedet as l LEFT JOIN llx_product as p ON l.fk_product = p.rowid WHERE l.fk_facture = 113 ORDER BY l.rang, l.rowid
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, name, label, type, size, elementtype, fieldunique, fieldrequired, param, pos, alwayseditable, perms, langs, list, printable, totalizable, fielddefault, fieldcomputed, entity, enabled, help, aiprompt, css, cssview, csslist FROM llx_extrafields WHERE elementtype = 'facturedet' ORDER BY pos
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 Call getNextNumRef with FACTURE_ADDON = mod_facture_mercure, thirdparty=pseudo_1_x pseudo_2_x, type=, mode=next
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 functions2::get_next_value mode=next
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=SELECT MAX(SUBSTRING(ref, 8, 5)) as val FROM llx_facture WHERE ref LIKE 'RE____-_____' AND ref NOT LIKE '(PROV%)' AND entity IN (1)
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 functions2::get_next_value return RE2511-00037
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 Facture::update_price
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, qty, subprice as up, remise_percent, total_ht, total_tva as total_tva, total_ttc, total_localtax1 as total_localtax1, total_localtax2 as total_localtax2, tva_tx as vatrate, localtax1_tx, localtax2_tx, localtax1_type, localtax2_type, info_bits, product_type, situation_percent, multicurrency_total_ht, multicurrency_total_tva, multicurrency_total_ttc FROM llx_facturedet WHERE fk_facture = 113 AND product_type <> 9 ORDER by rowid
2025-11-17 20:41:14 WARNING 89.12.34.6 3326321 31151 Price.lib::calcul_price_total Warning: function is called with parameter seller that is missing
2025-11-17 20:41:14 INFO 89.12.34.6 3326321 31151 Price.lib::calcul_price_total qty=1 pu=24.00000000 remise_percent_ligne=0 txtva=0.0000 uselocaltax1_rate=0 uselocaltax2_rate=0 remise_percent_global=0 price_base_type=HT type=1 progress=100
2025-11-17 20:41:14 INFO 89.12.34.6 3326321 31151 Price.lib::calcul_price_total MAIN_ROUNDING_RULE_TOT= pu=24.00000000 qty=1 price_base_type=HT total_ht=24-total_vat=0-total_ttc=24
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 Facture::update_price
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_facture SET total_ht = 24, total_tva = 0, localtax1 = 0, localtax2 = 0, total_ttc = 24, multicurrency_total_ht = 24, multicurrency_total_tva = 0, multicurrency_total_ttc = 24 WHERE rowid = 113
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 Facture::validate
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_facture SET ref = 'RE2511-00037', fk_statut = 1, fk_user_valid = 3, date_valid = '2025-11-17 21:41:14' WHERE rowid = 113
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_societe SET client = 1 WHERE rowid = 37
2025-11-17 20:41:14 INFO 89.12.34.6 3326321 31151 Trigger 'ActionsAuto' for action 'BILL_VALIDATE' launched by /var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/core/triggers/interface_50_modAgenda_ActionsAuto.class.php. id=113
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 CActionComm::fetch
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=SELECT id, code, type, libelle as label, color, active, picto FROM llx_c_actioncomm WHERE code='AC_OTH_AUTO'
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 ActionComm::add
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=INSERT INTO llx_actioncomm(ref,datec,datep,datep2,durationp,fk_action,code,ref_ext,fk_soc,fk_project,note,fk_contact,fk_user_author,fk_user_action,label,percent,priority,fulldayevent,location,transparency,fk_element,elementtype,fk_bookcal_calendar,entity,extraparams,email_msgid,email_from,email_sender,email_to,email_tocc,email_tobcc,email_subject,errors_to,recurid,recurrule,recurdateend,num_vote,event_paid,status,ip) VALUES ('(PROV)', '2025-11-17 21:41:14', '2025-11-17 21:41:14', '2025-11-17 21:41:14', '0', 40,'AC_BILL_VALIDATE', null, 37, null, 'Rechnung RE2511-00037 freigegeben', null, 3, 3, 'Rechnung RE2511-00037 freigegeben', '-1', '0', '0', '', '0', 113, 'invoice', null, 1,null, null, null, null, null, null, null, null, null, null, null, null, null, 0, 0, '89.12.34.6')
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_actioncomm SET ref='739' WHERE id=739
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=INSERT INTO llx_actioncomm_resources(fk_actioncomm, element_type, fk_element, mandatory, transparency, answer_status) VALUES(739, 'user', 3, 0, 0, 0)
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_ecm_files set filename = CONCAT('RE2511-00037', SUBSTR(filename, 10)), filepath = 'facture/RE2511-00037' WHERE filename LIKE '(PROV113)%' AND filepath = 'facture/(PROV113)' and entity = 1
2025-11-17 20:41:14 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_ecm_files set filepath = 'facture/RE2511-00037' WHERE filepath = 'facture/(PROV113)' and entity = 1
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 debuglog - create invoice pdf document
2025-11-17 20:41:16 INFO 89.12.34.6 3326321 31151 commonGenerateDocument modele=sponge outputlangs->defaultlang=de_DE
2025-11-17 20:41:16 INFO 89.12.34.6 3326321 31151 pdf_getFormat Get paper format with mode=setup MAIN_PDF_FORMAT=EUA4 outputlangs->defaultlang=null and langs->defaultlang=de_DE
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 sql=SELECT code, label, width, height, unit FROM llx_c_paper_format WHERE code = 'EUA4'
2025-11-17 20:41:16 INFO 89.12.34.6 3326321 31151 write_file outputlangs->defaultlang=de_DE
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 sql=SELECT s.rowid, [...] FROM llx_societe as s LEFT JOIN llx_c_effectif as e ON s.fk_effectif = e.id LEFT JOIN llx_c_country as c ON s.fk_pays = c.rowid LEFT JOIN llx_c_stcomm as st ON s.fk_stcomm = st.id LEFT JOIN llx_c_forme_juridique as fj ON s.fk_forme_juridique = fj.code LEFT JOIN llx_c_departements as d ON s.fk_departement = d.rowid LEFT JOIN llx_c_regions as r ON d.fk_region = r.code_region LEFT JOIN llx_c_typent as te ON s.fk_typent = te.id LEFT JOIN llx_c_incoterms as i ON s.fk_incoterms = i.rowid WHERE s.entity IN (1) AND s.rowid = 37
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 Facture::getSommePaiement
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 sql=SELECT sum(amount) as amount, sum(multicurrency_amount) as multicurrency_amount FROM llx_paiement_facture WHERE fk_facture = 113
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 DiscountAbsolute::getSumCreditNotesUsed
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 sql=SELECT sum(rc.amount_ttc) as amount, sum(rc.multicurrency_amount_ttc) as multicurrency_amount FROM llx_societe_remise_except as rc, llx_facture as f WHERE rc.fk_facture_source=f.rowid AND rc.fk_facture = 113 AND f.type IN (0,2,5)
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 DiscountAbsolute::getSumDepositsUsed
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 sql=SELECT sum(rc.amount_ttc) as amount, sum(rc.multicurrency_amount_ttc) as multicurrency_amount FROM llx_societe_remise_except as rc, llx_facture as f WHERE rc.fk_facture_source=f.rowid AND rc.fk_facture = 113 AND f.type = 3
2025-11-17 20:41:16 INFO 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: dir=/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/documents/facture/RE2511-00037
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Directory '/var' is not found (does not exists or is outside open_basedir PHP setting).
2025-11-17 20:41:16 WARNING 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Fails to create directory '/var' (no permission to write into parent or directory already exists).
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Directory '/var/www' is not found (does not exists or is outside open_basedir PHP setting).
2025-11-17 20:41:16 WARNING 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Fails to create directory '/var/www' (no permission to write into parent or directory already exists).
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Directory '/var/www/vhosts' is not found (does not exists or is outside open_basedir PHP setting).
2025-11-17 20:41:16 WARNING 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Fails to create directory '/var/www/vhosts' (no permission to write into parent or directory already exists).
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Directory '/var/www/vhosts/hostg202.ae95a.provider.net' is not found (does not exists or is outside open_basedir PHP setting).
2025-11-17 20:41:16 WARNING 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Fails to create directory '/var/www/vhosts/hostg202.ae95a.provider.net' (no permission to write into parent or directory already exists).
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Directory '/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de' is not found (does not exists or is outside open_basedir PHP setting).
2025-11-17 20:41:16 WARNING 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Fails to create directory '/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de' (no permission to write into parent or directory already exists).
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Directory '/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest' is not found (does not exists or is outside open_basedir PHP setting).
2025-11-17 20:41:16 WARNING 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Fails to create directory '/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest' (no permission to write into parent or directory already exists).
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Directory '/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/documents/facture/RE2511-00037' is not found (does not exists or is outside open_basedir PHP setting).
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: Directory '/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/documents/facture/RE2511-00037' created
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 Facture::getListOfPayments filtertype= multicurrency=0 mode=0
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 sql=SELECT [...]
2025-11-17 20:41:16 DEBUG 89.12.34.6 3326321 31151 sql=SELECT [...]
2025-11-17 20:41:16 INFO 89.12.34.6 3326321 31151 functions.lib::dol_mkdir: dir=/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/documents/admin/temp/
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid FROM llx_facture WHERE fk_facture_source = 113 AND type < 2 AND fk_statut = 1 ORDER BY fk_statut DESC
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 Facture::fetchObjectLink
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, fk_source, sourcetype, fk_target, targettype FROM llx_element_element WHERE (fk_source = 113 AND sourcetype = 'facture') OR (fk_target = 113 AND targettype = 'facture') ORDER BY sourcetype
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 Subscription::fetch
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, fk_type, fk_adherent, datec, tms, dateadh as dateh, datef, subscription, note as note_public, fk_bank FROM llx_subscription WHERE rowid = 95
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 Facture::getIdContact
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT [...]
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 Facture::getIdContact
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT ec.fk_socpeople FROM llx_element_contact as ec, llx_socpeople as c, llx_c_type_contact as tc WHERE ec.element_id = 113 AND ec.fk_socpeople = c.rowid AND c.entity IN (1) AND ec.fk_c_type_contact = tc.rowid AND tc.element = 'facture' AND tc.source = 'external' AND tc.code = 'BILLING' AND tc.active = 1
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT [...]
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT [...]
2025-11-17 20:41:17 INFO 89.12.34.6 3326321 31151 DolDeprecationHandler: Accessing deprecated property 'cond_reglement' on class Facture. Use 'depr_cond_reglement' instead. From /var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/core/modules/facture/doc/pdf_sponge.modules.php:1392.
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 Account::fetch
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT ba.rowid, [...] WHERE ba.entity IN (1) AND ba.rowid = 1
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, name, label, type, size, elementtype, fieldunique, fieldrequired, param, pos, alwayseditable, perms, langs, list, printable, totalizable, fielddefault, fieldcomputed, entity, enabled, help, aiprompt, css, cssview, csslist FROM llx_extrafields WHERE elementtype = 'bank_account' ORDER BY pos
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 Account::fetch
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT ba.rowid, [...] WHERE ba.entity IN (1) AND ba.rowid = 1
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 Facture::fetchPreviousNextSituationInvoice
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, type, situation_cycle_ref, situation_counter FROM llx_facture WHERE rowid <> 113 AND entity = 1 AND situation_cycle_ref = 0 ORDER BY situation_counter ASC
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 DiscountAbsolute::getSumCreditNotesUsed
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT sum(rc.amount_ttc) as amount, sum(rc.multicurrency_amount_ttc) as multicurrency_amount FROM llx_societe_remise_except as rc, llx_facture as f WHERE rc.fk_facture_source=f.rowid AND rc.fk_facture = 113 AND f.type IN (0,2,5)
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 DiscountAbsolute::getSumDepositsUsed
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT sum(rc.amount_ttc) as amount, sum(rc.multicurrency_amount_ttc) as multicurrency_amount FROM llx_societe_remise_except as rc, llx_facture as f WHERE rc.fk_facture_source=f.rowid AND rc.fk_facture = 113 AND f.type = 3
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 Facture::getListOfPayments filtertype= multicurrency=0 mode=1
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT p.ref, pf.amount, pf.multicurrency_amount, p.fk_paiement, p.datep, p.num_paiement as num, t.code, p.ref_ext, p.fk_bank FROM llx_paiement_facture as pf, llx_paiement as p, llx_c_paiement as t WHERE pf.fk_facture = 113 AND pf.fk_paiement = p.rowid AND p.fk_paiement = t.id AND p.entity IN (1)
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 EcmFiles::fetch
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT [...] t.filename = 'RE2511-00037.pdf' AND t.entity = 1
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, name, label, type, size, elementtype, fieldunique, fieldrequired, param, pos, alwayseditable, perms, langs, list, printable, totalizable, fielddefault, fieldcomputed, entity, enabled, help, aiprompt, css, cssview, csslist FROM llx_extrafields WHERE elementtype = 'ecm_files' ORDER BY pos
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 EcmFiles::create
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT MAX(position) as maxposition FROM llx_ecm_files WHERE filepath ='facture/RE2511-00037'
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=INSERT INTO llx_ecm_files(ref,label,share,entity,filename,filepath,fullpath_orig,description,keywords,cover,position,gen_or_uploaded,extraparams,date_c,tms,fk_user_c,fk_user_m,acl,src_object_type,src_object_id,agenda_id) VALUES ( '6f348dc5d87b8bfb7cfb70d8398bd8b3', 'b3bc0412ad9fa0a682799786f1f0b24c', NULL, 1, 'RE2511-00037.pdf', 'facture/RE2511-00037', '', '', '', NULL, 1, 'generated', NULL, '2025-11-17 21:41:17', '2025-11-17 21:41:17', 3, NULL, NULL, 'facture', 113, NULL)
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=UPDATE llx_facture SET last_main_doc = 'facture/RE2511-00037/RE2511-00037.pdf' WHERE rowid = 113
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 debuglog - finish invoice handling
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 COMMIT Transaction
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT transkey, transvalue FROM llx_overwrite_trans where (lang='de_DE' OR lang IS NULL) AND entity IN (0, 0,1) ORDER BY lang DESC
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, entity, module, label, type_template, topic, email_from, joinfiles, content, content_lines, lang, email_from, email_to, email_tocc, email_tobcc FROM llx_c_email_templates WHERE (type_template = 'member' OR type_template = 'all') AND entity IN (0,1) AND (private = 0 OR fk_user = 3) AND active = 1 AND label = 'Beitrag_keinSEPA' AND (lang = 'de_DE' OR lang IS NULL OR lang = '') AND entity IN(0,1) ORDER BY position ASC, lang DESC, label ASC
2025-11-17 20:41:17 INFO 89.12.34.6 3326321 31151 DolDeprecationHandler: Accessing deprecated property 'projet' on class Adherent. Use 'project' instead. From /var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/core/lib/functions.lib.php:9665.
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, name, label, type, size, elementtype, fieldunique, fieldrequired, param, pos, alwayseditable, perms, langs, list, printable, totalizable, fielddefault, fieldcomputed, entity, enabled, help, aiprompt, css, cssview, csslist FROM llx_extrafields WHERE elementtype = 'adherent' ORDER BY pos
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT rowid, datenschutz, unterlagen_in_papier, sepamandat, sepa_unterzeichnet, mindejahrig, gesetzlicher_vertreter FROM llx_adherent_extrafields WHERE fk_object = 195
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT t.localtax1, t.localtax2 FROM llx_c_tva as t, llx_c_country as c WHERE t.fk_pays = c.rowid AND c.code = 'DE' AND t.active = 1 AND t.entity IN (1) AND t.localtax1_type <> '0'
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 sql=SELECT t.localtax1, t.localtax2 FROM llx_c_tva as t, llx_c_country as c WHERE t.fk_pays = c.rowid AND c.code = 'DE' AND t.active = 1 AND t.entity IN (1) AND t.localtax2_type <> '0'
2025-11-17 20:41:17 INFO 89.12.34.6 3326321 31151 files.lib.php::dol_dir_list path=/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/documents/facture/RE2511-00037 types=files recursive=0 filter="RE2511\\-00037[^\\-]+" excludefilter=["(\\.meta|_preview.*\\.png)$","^\\."]
2025-11-17 20:41:17 INFO 89.12.34.6 3326321 31151 sendEmail msgishtml=1
2025-11-17 20:41:17 INFO 89.12.34.6 3326321 31151 CMailFile::CMailfile: charset=UTF-8 from=company cty e.V. <mail@company-cty.de>, to=pseudo_1pseudo_2@gmail.com, addr_cc=, addr_bcc=, errors_to=, replyto= trackid=mem195 sendcontext=standard
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 CMailFile::CMailfile: subject=[[TEST] company cty e.V.] MItgliedsbeitrag erfasst, deliveryreceipt=0, msgishtml=1
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 CMailFile::CMailfile: msgishtml=1
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 CMailFile::CMailfile: filename_list[0]=/var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/documents/facture/RE2511-00037/RE2511-00037.pdf, mimetype_list[0]=application/pdf mimefilename_list[0]=RE2511-00037.pdf cid_list[0]=
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 CMailFile::CMailfile: sendmode=mail addr_bcc=, replyto=company cty e.V. <mail@company-cty.de>
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 CMailFile::write_smtpheaders smtp_header=
From: "=?UTF-8?B?RG9yZnZlcmVpbiBCb3JsYXMgZS5WLg==?=" <mail@company-cty.de>
Return-Path: <mail@company-cty.de>
Reply-To: mail@company-cty.de
Date: Mon, 17 Nov 2025 21:41:17 +0100
Message-ID: <1763412077.748.phpmail-dolibarr-mem195@443e3e72d04c720b4a114f9468b11e6d8eb0fe56>
X-Dolibarr-TRACKID: mem195@443e3e72d04c720b4a114f9468b11e6d8eb0fe56
X-RemoteAddr: 89.12.34.6
X-Mailer: Dolibarr version 22.0.3 (using php mail)
Mime-Version: 1.0
Content-Type: multipart/mixed;
boundary="multipart_x.1763412077.x_boundary"
Content-Transfer-Encoding: 8bit
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 CMailFile::write_mimeheaders mime_header=
X-attachments: RE2511-00037.pdf
2025-11-17 20:41:17 INFO 89.12.34.6 3326321 31151 CMailFile::write_files: i=0 /var/www/vhosts/hostg202.ae95a.provider.net/company-cty.de/erptest/htdocs/documents/facture/RE2511-00037/RE2511-00037.pdf
2025-11-17 20:41:17 NOTICE 89.12.34.6 3326321 31151 CMailFile::sendfile addr_to=pseudo_1pseudo_2@gmail.com, subject=[[TEST] company cty e.V.] MItgliedsbeitrag erfasst
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 CMailFile::sendfile: mail start, additionnal_parameters=
2025-11-17 20:41:17 DEBUG 89.12.34.6 3326321 31151 CMailFile::sendfile: mail end success
Full Log on Pastebin: dolibarr - syslog contribution - Pastebin.com
I can’t identify any intermediate trigger or notification calls that would disrupt the planned process of creating an invoice and a PDF document with the intended third party payment terms, as defined in the source code.
The PDF document generation starts at 20:41:16 (UTC). The result is the created file “RE2511-00037.pdf”. This time is identical to the file’s timestamps (CET) in the filesystem when I check the console.
bash-5.2$ pwd
/company-cty.de/erptest/htdocs/documents/facture/RE2511-00037
bash-5.2$ ls -la --time-style=full-iso
insgesamt 52
drwxrwx--x 2 hosting209502 psacln 4096 2025-11-17 21:41:17.185898791 +0100 .
drwxr-xr-x 39 hosting209502 psacln 4096 2025-11-17 21:41:16.897883804 +0100 ..
-rw-rw---- 1 hosting209502 psacln 43149 2025-11-17 21:41:17.185898791 +0100 RE2511-00037.pdf
Any suggestions?