Bug 14635 - Printerdriver upload 4.14rc1 not working
Summary: Printerdriver upload 4.14rc1 not working
Status: RESOLVED FIXED
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: Printing (show other bugs)
Version: 4.14.0rc1
Hardware: All All
: P5 regression (vote)
Target Milestone: 4.14
Assignee: Karolin Seeger
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-02-07 11:52 UTC by Stefan Kania
Modified: 2021-03-01 10:13 UTC (History)
3 users (show)

See Also:


Attachments
logfile log.smbd (14.32 MB, text/plain)
2021-02-08 13:29 UTC, Stefan Kania
no flags Details
logfile log.smbd.old (20.25 MB, application/x-trash)
2021-02-08 13:30 UTC, Stefan Kania
no flags Details
vagrant environment to test (51.67 MB, application/gzip)
2021-02-08 14:13 UTC, Stefan Kania
no flags Details
Possible patch for master and 4.14 (3.71 KB, patch)
2021-02-16 14:07 UTC, Ralph Böhme
no flags Details
Patch for 4.14 cherry-picked from master (4.30 KB, patch)
2021-02-18 10:07 UTC, Ralph Böhme
gd: review+
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Stefan Kania 2021-02-07 11:52:41 UTC
I'm just testing setting up a printserver with 4.14. I use both, the
Sernet-packages and the packages from Louis van Belle on debian buster.
I have three print server running:
one with Sernet 4.14rc2
one with Louis 4.14rc1
one with Louis 4.13

All set up exactly the same with this smb.conf:
--------
[global]
      workgroup = EXAMPLE
      realm = EXAMPLE.NET
      security = ADS
      winbind refresh tickets = Yes
      winbind use default domain = yes
      template shell = /bin/bash
      idmap config * : range = 10000 - 19999
      idmap config EXAMPLE : backend = rid
      idmap config EXAMPLE : range =  10000000 - 19999999


[print$]
        path = /var/lib/samba/printers
        comment = printer drivers
        create mask = 0775
        inherit permissions = yes
        read only = no

[printers]
        path = /var/spool/samba
        comment = spooling directory
        create mask = 0700
        browsable = no
        read only = no
        printable = yes

--------

I set permission for all systems:
--------
chgrp -R 'domain admins' /var/lib/samba/printers/
chmod -R 775 /var/lib/samba/printers/
net rpc rights grant 'example\Domain Admins' SePrintOperatorPrivilege -k
-S <print-server-name>
--------

Set up Cups with two printers an I can see the printers:
-------
root@ps1:~# smbclient -L ps1 -k

        Sharename       Type      Comment
        ---------       ----      -------
        print$          Disk      printer drivers
        IPC$            IPC       IPC Service (Samba
4.14.0rc2-SerNet-Debian-1.buster)
        HL3230-ps1      Printer   HL3230-ps1
        HP6-ps1         Printer   HP6-ps1
SMB1 disabled -- no workgroup available
-------

I login at my windows-system with my domain-admin starting the "print
management app" Add all three print server. I can see the printers for
each print server (every printer server is showing it's own printers).

Then I click on "drivers" to add a new signed driver. Widows is showing
the progress bar for uploading the driver to the print server. On both
4.14 print servers the directory /var/lib/samba/printers/x86/3 is
created but empty, only the one with 4.13 has the files for the driver.
No error on the windows-system, no error on both of the Samba print servers.
The app is showing the driver as present! But there are no files on the
print server, only on the 4.13 system.
Comment 1 David Disseldorp 2021-02-07 23:57:32 UTC
@Stefan: would you be able to provide 4.13 and 4.14rc "log level = 10" logs captured across the driver upload attempt?
Comment 2 Stefan Kania 2021-02-08 09:52:15 UTC
Adding the driver files log level set to 10:

[2021/02/08 04:49:55.289195, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:428(messaging_recv_cb)
  messaging_recv_cb: Received message 0x31b len 91 (num_fds:0) from 1539
[2021/02/08 04:49:55.289220, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:651(notifyd_trigger)
  notifyd_trigger: Got trigger_msg action=1, filter=2, path=/var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}
[2021/02/08 04:49:55.289236, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var
[2021/02/08 04:49:55.289247, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib
[2021/02/08 04:49:55.289255, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba
[2021/02/08 04:49:55.289263, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers
[2021/02/08 04:49:55.289271, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers/x64
[2021/02/08 04:49:55.297774, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:428(messaging_recv_cb)
  messaging_recv_cb: Received message 0x31b len 103 (num_fds:0) from 1539
[2021/02/08 04:49:55.297794, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:651(notifyd_trigger)
  notifyd_trigger: Got trigger_msg action=1, filter=1, path=/var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}/SET3876.tmp
[2021/02/08 04:49:55.297804, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var
[2021/02/08 04:49:55.297812, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib
[2021/02/08 04:49:55.297820, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba
[2021/02/08 04:49:55.297827, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers
[2021/02/08 04:49:55.297835, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers/x64
[2021/02/08 04:49:55.297843, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}
[2021/02/08 04:49:55.302435, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:428(messaging_recv_cb)
  messaging_recv_cb: Received message 0x31b len 103 (num_fds:0) from 1539
[2021/02/08 04:49:55.302454, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:651(notifyd_trigger)
  notifyd_trigger: Got trigger_msg action=3, filter=4, path=/var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}/SET3876.tmp
[2021/02/08 04:49:55.302463, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var
[2021/02/08 04:49:55.302471, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib
[2021/02/08 04:49:55.302482, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba
[2021/02/08 04:49:55.302490, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers
[2021/02/08 04:49:55.302497, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers/x64
[2021/02/08 04:49:55.302504, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}
[2021/02/08 04:49:55.302768, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:428(messaging_recv_cb)
  messaging_recv_cb: Received message 0x31b len 103 (num_fds:0) from 1539
[2021/02/08 04:49:55.302783, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:651(notifyd_trigger)
  notifyd_trigger: Got trigger_msg action=3, filter=0, path=/var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}/SET3876.tmp
[2021/02/08 04:49:55.302792, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var
[2021/02/08 04:49:55.302800, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib
[2021/02/08 04:49:55.302807, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba
[2021/02/08 04:49:55.302814, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers
[2021/02/08 04:49:55.302821, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers/x64
[2021/02/08 04:49:55.302828, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}
[2021/02/08 04:49:55.312408, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:428(messaging_recv_cb)
  messaging_recv_cb: Received message 0x31b len 103 (num_fds:0) from 1539
[2021/02/08 04:49:55.312428, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:651(notifyd_trigger)
  notifyd_trigger: Got trigger_msg action=2, filter=1, path=/var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}/SET3876.tmp
[2021/02/08 04:49:55.312437, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var
[2021/02/08 04:49:55.312446, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib
[2021/02/08 04:49:55.312453, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba
[2021/02/08 04:49:55.312460, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers
[2021/02/08 04:49:55.312467, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers/x64
[2021/02/08 04:49:55.312474, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}
[2021/02/08 04:49:55.314582, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:428(messaging_recv_cb)
  messaging_recv_cb: Received message 0x31b len 103 (num_fds:0) from 1539
[2021/02/08 04:49:55.314602, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:651(notifyd_trigger)
  notifyd_trigger: Got trigger_msg action=1, filter=1, path=/var/lib/samba/printers/x64/{829226F7-38E1-47F4-AD53-A59E75E5EEA8}/SET3876.tmp
[2021/02/08 04:49:55.314611, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var
[2021/02/08 04:49:55.314620, 10, pid=1527, effective(0, 0), real(0, 0)] ../../source3/smbd/notifyd/notifyd.c:667(notifyd_trigger)
  notifyd_trigger: Trying path /var/lib
[2021/02/08 04:50:00.419537, 10, pid=1529, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:428(messaging_recv_cb)
  messaging_recv_cb: Received message 0x203 len 25 (num_fds:0) from 1539
[2021/02/08 04:50:00.419606, 10, pid=1529, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/spoolss/srv_spoolss_nt.c:1518(do_drv_upgrade_printer)
  do_drv_upgrade_printer: Got message for new driver [HP Universal Printing PS]
[2021/02/08 04:50:00.419665,  5, pid=1529, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:258(make_internal_ncacn_conn)
  make_internal_ncacn_conn: Create pipe requested winreg
[2021/02/08 04:50:00.419745,  4, pid=1529, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:304(make_internal_ncacn_conn)
  Created internal pipe winreg
[2021/02/08 04:50:00.419838,  1, pid=1529, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:478(ndr_print_function_debug)
       winreg_OpenHKLM: struct winreg_OpenHKLM
          in: struct winreg_OpenHKLM
              system_name              : NULL
              access_mask              : 0x02000000 (33554432)
                     0: KEY_QUERY_VALUE          
                     0: KEY_SET_VALUE            
                     0: KEY_CREATE_SUB_KEY       
                     0: KEY_ENUMERATE_SUB_KEYS   
                     0: KEY_NOTIFY               
                     0: KEY_CREATE_LINK          
                     0: KEY_WOW64_64KEY          
                     0: KEY_WOW64_32KEY          
[2021/02/08 04:50:00.419950,  7, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_api.c:143(regkey_open_onelevel)
  regkey_open_onelevel: name = [HKLM]
[2021/02/08 04:50:00.419995,  4, pid=1529, effective(0, 0), real(0, 0)] ../../source3/smbd/sec_ctx.c:216(push_sec_ctx)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2021/02/08 04:50:00.420022,  4, pid=1529, effective(0, 0), real(0, 0)] ../../source3/smbd/uid.c:562(push_conn_ctx)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2021/02/08 04:50:00.420045,  4, pid=1529, effective(0, 0), real(0, 0)] ../../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2021/02/08 04:50:00.420067,  5, pid=1529, effective(0, 0), real(0, 0)] ../../libcli/security/security_token.c:47(security_token_debug)
  Security token: (NULL)
[2021/02/08 04:50:00.420090,  5, pid=1529, effective(0, 0), real(0, 0)] ../../source3/auth/token_util.c:874(debug_unix_user_token)
  UNIX token of user 0
  Primary group is 0 and contains 0 supplementary groups
[2021/02/08 04:50:00.420218,  4, pid=1529, effective(0, 0), real(0, 0)] ../../source3/smbd/sec_ctx.c:438(pop_sec_ctx)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2021/02/08 04:50:00.420250, 10, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_backend_db.c:887(regdb_open)
  regdb_open: registry db opened. refcount reset (1)
[2021/02/08 04:50:00.420278, 10, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_cachehook.c:125(reghook_cache_find)
  reghook_cache_find: Searching for keyname [\HKLM]
[2021/02/08 04:50:00.420302, 10, pid=1529, effective(0, 0), real(0, 0)] ../../source3/lib/adt_tree.c:367(pathtree_find)
  pathtree_find: Enter [\HKLM]
[2021/02/08 04:50:00.420340, 10, pid=1529, effective(0, 0), real(0, 0)] ../../source3/lib/adt_tree.c:440(pathtree_find)
  pathtree_find: Exit
[2021/02/08 04:50:00.420362, 10, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_cachehook.c:130(reghook_cache_find)
  reghook_cache_find: found ops 0x7fdd6cfbb020 for key [\HKLM]
[2021/02/08 04:50:00.420426,  1, pid=1529, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:478(ndr_print_function_debug)
       winreg_OpenHKLM: struct winreg_OpenHKLM
          out: struct winreg_OpenHKLM
              handle                   : *
                  handle: struct policy_handle
                      handle_type              : 0x00000001 (1)
                      uuid                     : cdafa9b6-58a5-480d-9bd4-6f9c16f77d55
              result                   : WERR_OK
[2021/02/08 04:50:00.420552,  1, pid=1529, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:478(ndr_print_function_debug)
       winreg_OpenKey: struct winreg_OpenKey
          in: struct winreg_OpenKey
              parent_handle            : *
                  parent_handle: struct policy_handle
                      handle_type              : 0x00000001 (1)
                      uuid                     : cdafa9b6-58a5-480d-9bd4-6f9c16f77d55
              keyname: struct winreg_String
                  name_len                 : 0x0086 (134)
                  name_size                : 0x0086 (134)
                  name                     : *
                      name                     : 'SOFTWARE\Microsoft\Windows NT\CurrentVersion\Print\Printers\HL3230'
              options                  : 0x00000000 (0)
                     0: REG_OPTION_VOLATILE      
                     0: REG_OPTION_CREATE_LINK   
                     0: REG_OPTION_BACKUP_RESTORE
                     0: REG_OPTION_OPEN_LINK     
              access_mask              : 0x02000000 (33554432)
                     0: KEY_QUERY_VALUE          
                     0: KEY_SET_VALUE            
                     0: KEY_CREATE_SUB_KEY       
                     0: KEY_ENUMERATE_SUB_KEYS   
                     0: KEY_NOTIFY               
                     0: KEY_CREATE_LINK          
                     0: KEY_WOW64_64KEY          
                     0: KEY_WOW64_32KEY          
[2021/02/08 04:50:00.420758,  7, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_api.c:143(regkey_open_onelevel)
  regkey_open_onelevel: name = [SOFTWARE]
[2021/02/08 04:50:00.420784, 10, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_backend_db.c:859(regdb_open)
  regdb_open: incrementing refcount (1->2)
[2021/02/08 04:50:00.420811, 10, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_cachehook.c:125(reghook_cache_find)
  reghook_cache_find: Searching for keyname [\HKLM\SOFTWARE]
[2021/02/08 04:50:00.420834, 10, pid=1529, effective(0, 0), real(0, 0)] ../../source3/lib/adt_tree.c:367(pathtree_find)
  pathtree_find: Enter [\HKLM\SOFTWARE]
[2021/02/08 04:50:00.420859, 10, pid=1529, effective(0, 0), real(0, 0)] ../../source3/lib/adt_tree.c:440(pathtree_find)
  pathtree_find: Exit
[2021/02/08 04:50:00.420881, 10, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_cachehook.c:130(reghook_cache_find)
  reghook_cache_find: found ops 0x7fdd6cfbb020 for key [\HKLM\SOFTWARE]
[2021/02/08 04:50:00.420933,  7, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_api.c:143(regkey_open_onelevel)
  regkey_open_onelevel: name = [Microsoft]
[2021/02/08 04:50:00.420958, 10, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_backend_db.c:859(regdb_open)
  regdb_open: incrementing refcount (2->3)
[2021/02/08 04:50:00.420983, 10, pid=1529, effective(0, 0), real(0, 0), class=registry] ../../source3/registry/reg_cachehook.c:125(reghook_cache_find)
  reghook_cache_find: Searching for keyname [\HKLM\SOFTWARE\Microsoft]
Comment 3 Ralph Böhme 2021-02-08 09:56:02 UTC
(In reply to Stefan Kania from comment #2)
Are you sure that's all? I would think the log should be bigger then what you pasted. *scratches head* I bet Jeremy and I broke this with the VFS changes.
Comment 4 Stefan Kania 2021-02-08 10:00:34 UTC
Yes, I started "tail -n /var/log/log.smbd" with "log level = 10 " in smb.conf. Then I chose the driver to upload (in Windows) and before I pressed OK to finally upload the driver, I cleared the output from the "tail -f". Then I pressed "OK" and what you see is all I get.
Comment 5 David Disseldorp 2021-02-08 10:41:37 UTC
hmm, yeah this log does appear truncated. I'd expect to see a AddPrinterDriver[Ex] call somewhere. Could logrotate or something be getting in the way?
Comment 6 Stefan Kania 2021-02-08 10:48:31 UTC
I opened the log with "tail -f" and copied everything from the console that appears on the screen. I did not close the log, nothing. So no logrotate could remove something. I did it again with the same result. 

But that's exactly what I said. Windows is showing the window copying the files, no message at all. An message on the print server and the directory /var/lib/samba/printers/x86/3 was created but empty.
Comment 7 Ralph Böhme 2021-02-08 11:00:36 UTC
(In reply to Stefan Kania from comment #6)
well, if "max log size" is in effect and gets triggered, smbd will close the logfile you're polling and open a new one and use that instead, causing tail -f to miss all that. Can you check whether this could be happening?

If not, I guess a network trace would also be good to get a high level overview of what's going on.
Comment 8 Stefan Kania 2021-02-08 13:29:38 UTC
Created attachment 16436 [details]
logfile log.smbd

This is the logfile with log lecel set to 10
Comment 9 Stefan Kania 2021-02-08 13:30:35 UTC
Created attachment 16437 [details]
logfile log.smbd.old

The second log file
Comment 10 Stefan Kania 2021-02-08 13:31:47 UTC
The two logfiles where generated only during the process of adding the printer driver
Comment 11 Ralph Böhme 2021-02-08 13:53:03 UTC
(In reply to Stefan Kania from comment #10)
Thanks. I don't see any obvious unexpected errors with emacs smb-logmode. *scratches head*
Comment 12 Stefan Kania 2021-02-08 14:13:10 UTC
Created attachment 16439 [details]
vagrant environment to test

This tar.gz file is my Vagrant environment. If you want, you can test it with VirtualBox. The Vagrantfile will create DC (4.14) one host "printserver" with 4.14 and one "printserver13" with 4.13. just join a windows-system, creat a cups-printer and you can test it.
Comment 13 Ralph Böhme 2021-02-16 14:07:25 UTC
Created attachment 16452 [details]
Possible patch for master and 4.14
Comment 14 Samba QA Contact 2021-02-17 19:54:03 UTC
This bug was referenced in samba master:

8c1fd86db873f0326faf1cefa731a03709f8ac7f
70063c523bff5e471eac2b011b243c5aa0c4bee1
718f7b1a84f1c6eb35d52232a8573370f45add56
Comment 15 Ralph Böhme 2021-02-18 10:07:36 UTC
Created attachment 16465 [details]
Patch for 4.14 cherry-picked from master
Comment 16 Guenther Deschner 2021-02-19 12:25:30 UTC
Comment on attachment 16465 [details]
Patch for 4.14 cherry-picked from master

LGTM
Comment 17 Guenther Deschner 2021-02-19 12:27:53 UTC
Karolin, please add to v4-14, thanks!
Comment 18 Karolin Seeger 2021-02-22 07:26:53 UTC
(In reply to Guenther Deschner from comment #17)
Pushed to autobuild-v4-14-test.
Comment 19 Samba QA Contact 2021-02-22 12:01:05 UTC
This bug was referenced in samba v4-14-test:

5b1a5b776a7bed76695599211397469666fb2142
b30a1950e260fb7fd098da2deff608b7c505ef0d
1f520ec35e151bcde8103ba6cfbdced67b242d0a
Comment 20 Karolin Seeger 2021-02-22 12:05:07 UTC
Pushed to v4-14-test.
Closing out bug report.

Thanks!
Comment 21 Samba QA Contact 2021-03-01 10:13:36 UTC
This bug was referenced in samba v4-14-stable (Release samba-4.14.0rc4):

5b1a5b776a7bed76695599211397469666fb2142
b30a1950e260fb7fd098da2deff608b7c505ef0d
1f520ec35e151bcde8103ba6cfbdced67b242d0a