hi, In parts this seems to be an older issue, it happens also with a couple of earlier versions. Same setup and tdbs work fine on linux though.A single connection on a t2000 server is already extremly sloooow/unusable not speaking about a couple connections in parallel. Using truss I see thousands of: 29241: fcntl(22, F_SETLKW64, 0xFFBFDF10) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDFF0) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDE18) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDEF8) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDF10) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDFF0) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDE18) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDEF8) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDF10) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDFF0) = 0 29241: fcntl(22, F_SETLKW64, 0xFFBFDE18) = 0 Without any actions on the client (just watching the queue etc.) I did put a debuglevel 10 output here: https://www.desy.de/~chbeyer/dampf/forum/samba_debug_10.tar I am really highly depending on this to work in a couple of weeks to get central printservice back aon my sun cluster which worked as a charme for years with earlier versions. Thanks for any help and please tell me if you need any further information/help and so on !!! cheers christoph
(In reply to comment #0) > hi, > > In parts this seems to be an older issue, it happens also with a couple of > earlier versions. Same setup and tdbs work fine on linux though.A single > connection on a t2000 server is already extremly sloooow/unusable not speaking > about a couple connections in parallel. Using truss I see thousands of: > > 29241: fcntl(22, F_SETLKW64, 0xFFBFDF10) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDFF0) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDE18) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDEF8) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDF10) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDFF0) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDE18) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDEF8) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDF10) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDFF0) = 0 > 29241: fcntl(22, F_SETLKW64, 0xFFBFDE18) = 0 can you check what file descriptor 22 is ? > I did put a debuglevel 10 output here: > > https://www.desy.de/~chbeyer/dampf/forum/samba_debug_10.tar Hm, that does not really contain a lot. just a client printing something and receiving backchannel print job notifies. Could you please try to reproduce that within a broader scope, catch longer logfiles, maybe also include a network trace. Thanks
Hi Guenther, thanks for the reply ! I don't think further network traces will shed any light on this, seems to be a file locking problem on solaris (?) (will do any network tracing anyway of course) I found some older stuff about it here: http://lists.samba.org/archive/samba-technical/2002-April/020926.html Do you think my tdb file could be corrupted in a way that only effects solaris and not linux, becaus the same tdb works just fine there :( ? I will try to figure out which descriptor 22 is ... cheers christoph
Hi again, I tried to figure out what is behind filedescriptor 22, without much luck, lsof gives: smbd 148 nobody 6u FIFO 0x60047659980 0t1 18770605 (fifofs) PIPE->0x60047659a10 smbd 148 nobody 7u FIFO 0x60047659a10 0t1 18770605 (fifofs) PIPE->0x60047659980 smbd 148 nobody 8u FIFO 0x60035065e40 0t0 18770606 (fifofs) PIPE->0x60035065ed0 smbd 148 nobody 9w unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 10u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 11u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 12u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 13u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 14u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 15r DOOR 0t0 52 /var/run/name_service_door (door to nscd[303]) (FA:->0x6003fe62200) smbd 148 nobody 16u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 17u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 18u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 20u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 21u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 22u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 23u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 24u unknown file system type (ufs), v_op: 0x60036ad2900 smbd 148 nobody 25u FIFO 0x6003be2a7e0 0t0 17840601 (fifofs) PIPE->0x6003be2a870 smbd 148 nobody 26u FIFO 0x6003be2a870 0t0 17840601 (fifofs) PIPE->0x6003be2a7e0 smbd 148 nobody 27u FIFO 0x60045dff080 0t0 17840602 (fifofs) PIPE->0x60045dff110 smbd 148 nobody 28u unix 105,4866 0t346947 55050244 /devices/pseudo/tl@0:ticots->/global/spool/printsrv10/samba-3.5.2/var/locks/winbindd_privileged/pipe (0x6004aaaeea0->0x6004a449d00) cheers christoph
hi again, just installed lsof: [printsrv9] /global/spool/bin/DTraceToolkit-0.99 # lsof -d 22 COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME ypbind 443 root 22ww VREG 85,1 140 23557 /var/yp/binding/desy.afs/cache_binding inetd 530 root 22u VCHR 105,126 55050244 /devices/pseudo/tl@0:ticots->timod->tl xntpd 533 root 22u IPv4 0x60040c6cf00 0t0 UDP *:65535 fmd 673 root 22u VCHR 105,152 55050244 /devices/pseudo/tl@0:ticots->timod->tl java 1606 root 22u IPv4 0x60036a75080 0t0 UDP *:65535 smbd 8018 root 22u unknown file system type (ufs), v_op: 0x6004149cf00 winbindd 8020 root 22r DOOR 0t0 51 /var/run/name_service_door (door to nscd[312]) (FA:->0x6003b56f200) winbindd 8039 root 22r DOOR 0t0 51 /var/run/name_service_door (door to nscd[312]) (FA:->0x6003b56f200) winbindd 8179 root 22r DOOR 0t0 51 /var/run/name_service_door (door to nscd[312]) (FA:->0x6003b56f200) winbindd 8180 root 22r DOOR 0t0 51 /var/run/name_service_door (door to nscd[312]) (FA:->0x6003b56f200) smbd 8181 root 22u unknown file system type (ufs), v_op: 0x6004149cf00 smbd 14326 root 22u unknown file system type (ufs), v_op: 0x6004149cf00 winbindd 14328 root 22r DOOR 0t0 51 /var/run/name_service_door (door to nscd[312]) (FA:->0x6003b56f200) smbd 22973 root 22u unknown file system type (ufs), v_op: 0x6004149cf00 does this help in nay way ? cheers christoph PS: will try 3.5.4 tomorrow...
OK, same problem with 3.5.4 are there any chance to get tihis fixed or further debugged ? I'm realy depending on this to function on solaris :( Is there anything I can do ? cheers christoph
hi, just to clarify this, the smbd tries to make some byte range locking here and fails: 10 24063 92 smbd:- syscall -> fcntl 10 24063 812 smbd:- syscall <- fcntl 10 24063 876 smbd:- syscall -> fcntl 10 24063 893 smbd:- syscall <- fcntl 10 24063 80 smbd:- syscall -> fcntl 10 24063 827 smbd:- syscall <- fcntl 10 24063 3980 smbd:- syscall -> fcntl 10 24063 888 smbd:- syscall <- fcntl 10 24063 89 smbd:- syscall -> fcntl 10 24063 811 smbd:- syscall <- fcntl 10 24063 730 smbd:- syscall -> fcntl 10 24063 898 smbd:- syscall <- fcntl 10 24063 82 smbd:- syscall -> fcntl 10 24063 822 smbd:- syscall <- fcntl 10 24063 3949 smbd:- syscall -> fcntl 10 24063 918 smbd:- syscall <- fcntl 10 24063 80 smbd:- syscall -> fcntl 10 24063 971 smbd:- syscall <- fcntl 10 24063 662 smbd:- syscall -> fcntl 10 24063 962 smbd:- syscall <- fcntl 10 24063 84 smbd:- syscall -> fcntl 10 24063 819 smbd:- syscall <- fcntl 10 24063 3922 smbd:- syscall -> fcntl 10 24063 945 smbd:- syscall <- fcntl 10 24063 87 smbd:- syscall -> fcntl 10 24063 817 smbd:- syscall <- fcntl 10 24063 725 smbd:- syscall -> fcntl 10 24063 903 smbd:- syscall <- fcntl 10 24063 80 smbd:- syscall -> fcntl 10 24063 825 smbd:- syscall <- fcntl 10 24063 3924 smbd:- syscall -> fcntl A single connection with one client produces 50.000 + syscalls only for opening the printer properties. This makes samba prinitng unusable on any solaris 10 release, isn't this anything to be concerned ?????? [printsrv9] /global/spool/bin/DTraceToolkit-0.99/Bin # grep fcntl /tmp/pidcolors.log | wc -l 50498 ^^^^^^^^^^ !!!!!!!!!!!!!!! cheers christoph
hi, did some more digging, it is definetely the ntprinters.tdb file which is causing the locking trouble. Did 'tdbbackup -n 10000' and tried the resulting file but with no effect, still not working :( cheers christoph
Hi, some new aspects maybe for this vibrant bug-case during 'waiting time' the smbd seems to unpack and execute every single available printer of the server which takes forever or at least a lot of time, printer in this example is pubps7 which is printing a testpage: [ snip ] [2010/08/17 15:47:12.733217, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printEndTime], len: 4 [2010/08/17 15:47:12.733488, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:priority], len: 4 [2010/08/17 15:47:12.733759, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printKeepPrintedJobs], len: 1 [2010/08/17 15:47:12.734036, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printSpooling], len: 36 [2010/08/17 15:47:12.734314, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:objectGUID], len: 74 [2010/08/17 15:47:12.736274, 9] printing/nt_printing.c:4010(get_a_printer_2) Unpacked printer [pubps8a3] name [\\printsrv9\pubps8a3] running driver [HP LaserJet 8000 Series PS] printername: pubps8a3 [2010/08/17 15:47:12.736752, 10] printing/nt_printing.c:4549(get_a_printer_internal) get_a_printer: [pubps8] level 2 [2010/08/17 15:47:12.740892, 8] printing/nt_printing.c:2727(unpack_devicemode) Unpacked devicemode [\\adprint\pubps8](A4) [2010/08/17 15:47:12.741126, 8] printing/nt_printing.c:2729(unpack_devicemode) with a private section of 1148 bytes [2010/08/17 15:47:12.741363, 10] printing/nt_printing.c:2766(add_new_printer_key) add_new_printer_key: Inserted new data key [PrinterDriverData] [2010/08/17 15:47:12.741602, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormSize], len: 4 [2010/08/17 15:47:12.741866, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormTable], len: 144 [2010/08/17 15:47:12.742134, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormMapSize], len: 4 [2010/08/17 15:47:12.742404, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormMap], len: 69 [2010/08/17 15:47:12.742671, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormKeywordSize], len: 4 [2010/08/17 15:47:12.742942, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormKeyword], len: 50 [2010/08/17 15:47:12.743217, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:FreeMem], len: 4 [2010/08/17 15:47:12.743480, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:JobTimeOut], len: 4 [2010/08/17 15:47:12.743743, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:Protocol], len: 4 [2010/08/17 15:47:12.744007, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:PrinterDataSize], len: 4 [2010/08/17 15:47:12.744276, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:PrinterData], len: 560 [2010/08/17 15:47:12.744546, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:FeatureKeywordSize], len: 4 [2010/08/17 15:47:12.744818, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:FeatureKeyword], len: 131 [2010/08/17 15:47:12.745096, 10] printing/nt_printing.c:2766(add_new_printer_key) add_new_printer_key: Inserted new data key [DsSpooler] [2010/08/17 15:47:12.745327, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:versionNumber], len: 4 [2010/08/17 15:47:12.745588, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:driverName], len: 54 [2010/08/17 15:47:12.745848, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:portName], len: 40 [2010/08/17 15:47:12.746106, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printSeparatorFile], len: 2 [2010/08/17 15:47:12.746402, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printStartTime], len: 4 [2010/08/17 15:47:12.746667, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printEndTime], len: 4 [2010/08/17 15:47:12.746931, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:priority], len: 4 [2010/08/17 15:47:12.747193, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printKeepPrintedJobs], len: 1 [2010/08/17 15:47:12.747463, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printSpooling], len: 36 [2010/08/17 15:47:12.747731, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:objectGUID], len: 16 [2010/08/17 15:47:12.748167, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:location], len: 10 [2010/08/17 15:47:12.748431, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:description], len: 6 [2010/08/17 15:47:12.748698, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printerName], len: 14 [2010/08/17 15:47:12.748970, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:serverName], len: 20 [2010/08/17 15:47:12.749237, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:shortServerName], len: 20 [2010/08/17 15:47:12.749510, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:uNCName], len: 38 [2010/08/17 15:47:12.751625, 9] printing/nt_printing.c:4010(get_a_printer_2) Unpacked printer [pubps8] name [\\printsrv9\pubps8] running driver [HP LaserJet 8000 Series PS] printername: pubps8 [2010/08/17 15:47:12.752097, 10] printing/nt_printing.c:4549(get_a_printer_internal) get_a_printer: [pubps7h] level 2 [2010/08/17 15:47:12.756393, 8] printing/nt_printing.c:2727(unpack_devicemode) Unpacked devicemode [\\printsrv9\pubps7h](A4) [2010/08/17 15:47:12.756630, 8] printing/nt_printing.c:2729(unpack_devicemode) with a private section of 7804 bytes [2010/08/17 15:47:12.756867, 10] printing/nt_printing.c:2766(add_new_printer_key) add_new_printer_key: Inserted new data key [PrinterDriverData] [2010/08/17 15:47:12.757105, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormSize], len: 4 [2010/08/17 15:47:12.757373, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormTable], len: 210 [2010/08/17 15:47:12.757642, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormMapSize], len: 4 [2010/08/17 15:47:12.757912, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormMap], len: 77 [2010/08/17 15:47:12.758182, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormKeywordSize], len: 4 [2010/08/17 15:47:12.758456, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormKeyword], len: 55 [2010/08/17 15:47:12.758731, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:FreeMem], len: 4 [2010/08/17 15:47:12.758997, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:JobTimeOut], len: 4 [2010/08/17 15:47:12.759262, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:Protocol], len: 4 [2010/08/17 15:47:12.759527, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:PrinterDataSize], len: 4 [2010/08/17 15:47:12.759800, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:PrinterData], len: 560 [2010/08/17 15:47:12.760077, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:FeatureKeywordSize], len: 4 [2010/08/17 15:47:12.760352, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:FeatureKeyword], len: 640 [2010/08/17 15:47:12.760626, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:CombinedMediaStatus], len: 4 [2010/08/17 15:47:12.760900, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:HPDUMMY], len: 4 [2010/08/17 15:47:12.761168, 10] printing/nt_printing.c:2766(add_new_printer_key) add_new_printer_key: Inserted new data key [DsSpooler] [2010/08/17 15:47:12.761401, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printerName], len: 16 [2010/08/17 15:47:12.761660, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:shortServerName], len: 20 [2010/08/17 15:47:12.761925, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:serverName], len: 20 [2010/08/17 15:47:12.762191, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:uNCName], len: 40 [2010/08/17 15:47:12.762457, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:versionNumber], len: 4 [2010/08/17 15:47:12.762727, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:driverName], len: 48 [2010/08/17 15:47:12.762997, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:location], len: 14 [2010/08/17 15:47:12.763267, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:description], len: 82 [2010/08/17 15:47:12.763539, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:portName], len: 40 [2010/08/17 15:47:12.763812, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printSeparatorFile], len: 2 [2010/08/17 15:47:12.764087, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printStartTime], len: 4 [2010/08/17 15:47:12.764362, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printEndTime], len: 4 [2010/08/17 15:47:12.764632, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:priority], len: 4 [2010/08/17 15:47:12.764903, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printKeepPrintedJobs], len: 1 [2010/08/17 15:47:12.765182, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printSpooling], len: 36 [2010/08/17 15:47:12.765460, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:objectGUID], len: 74 [2010/08/17 15:47:12.767471, 9] printing/nt_printing.c:4010(get_a_printer_2) Unpacked printer [pubps7h] name [\\printsrv9\pubps7h] running driver [HP LaserJet 9040 mfp PS] printername: pubps7h [2010/08/17 15:47:12.767946, 10] printing/nt_printing.c:4549(get_a_printer_internal) get_a_printer: [pubps7a3] level 2 [2010/08/17 15:47:12.772096, 8] printing/nt_printing.c:2727(unpack_devicemode) Unpacked devicemode [\\printsrv9\pubps7a3](A3) [2010/08/17 15:47:12.772334, 8] printing/nt_printing.c:2729(unpack_devicemode) with a private section of 4468 bytes [2010/08/17 15:47:12.772572, 10] printing/nt_printing.c:2766(add_new_printer_key) add_new_printer_key: Inserted new data key [PrinterDriverData] [2010/08/17 15:47:12.772810, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:HPDUMMY], len: 4 [2010/08/17 15:47:12.773071, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormSize], len: 4 [2010/08/17 15:47:12.773335, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormTable], len: 152 [2010/08/17 15:47:12.773604, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormMapSize], len: 4 [2010/08/17 15:47:12.773872, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormMap], len: 69 [2010/08/17 15:47:12.774144, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormKeywordSize], len: 4 [2010/08/17 15:47:12.774416, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:TrayFormKeyword], len: 50 [2010/08/17 15:47:12.774692, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:FreeMem], len: 4 [2010/08/17 15:47:12.774952, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:JobTimeOut], len: 4 [2010/08/17 15:47:12.775217, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:Protocol], len: 4 [2010/08/17 15:47:12.775511, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:PrinterDataSize], len: 4 [2010/08/17 15:47:12.775785, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:PrinterData], len: 560 [2010/08/17 15:47:12.776054, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:FeatureKeywordSize], len: 4 [2010/08/17 15:47:12.776326, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:FeatureKeyword], len: 181 [2010/08/17 15:47:12.776599, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:HARDDISK], len: 20 [2010/08/17 15:47:12.776865, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:JOBRET], len: 20 [2010/08/17 15:47:12.777132, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:CURMEM], len: 4 [2010/08/17 15:47:12.777400, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:JRCHD], len: 4 [2010/08/17 15:47:12.777667, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:JRCJRET], len: 20 [2010/08/17 15:47:12.777939, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:JRCMINMEM], len: 4 [2010/08/17 15:47:12.778210, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:JRHDIOPT], len: 5 [2010/08/17 15:47:12.778484, 8] printing/nt_printing.c:3652(unpack_values) specific: [PrinterDriverData:JRHDNIOPT], len: 5 [2010/08/17 15:47:12.778763, 10] printing/nt_printing.c:2766(add_new_printer_key) add_new_printer_key: Inserted new data key [DsSpooler] [2010/08/17 15:47:12.778999, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:versionNumber], len: 4 [2010/08/17 15:47:12.779264, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:driverName], len: 54 [2010/08/17 15:47:12.779529, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:location], len: 14 [2010/08/17 15:47:12.779797, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:description], len: 64 [2010/08/17 15:47:12.780071, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:portName], len: 40 [2010/08/17 15:47:12.780343, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printSeparatorFile], len: 2 [2010/08/17 15:47:12.780620, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printStartTime], len: 4 [2010/08/17 15:47:12.780896, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printEndTime], len: 4 [2010/08/17 15:47:12.781165, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:priority], len: 4 [2010/08/17 15:47:12.781434, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printKeepPrintedJobs], len: 1 [2010/08/17 15:47:12.781713, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printSpooling], len: 36 [2010/08/17 15:47:12.781988, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:printerName], len: 18 [2010/08/17 15:47:12.782263, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:serverName], len: 20 [2010/08/17 15:47:12.782535, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:shortServerName], len: 20 [2010/08/17 15:47:12.782814, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:uNCName], len: 42 [2010/08/17 15:47:12.783089, 8] printing/nt_printing.c:3652(unpack_values) specific: [DsSpooler:objectGUID], len: 74 [2010/08/17 15:47:12.785073, 9] printing/nt_printing.c:4010(get_a_printer_2) Unpacked printer [pubps7a3] name [\\printsrv9\pubps7a3] running driver [HP LaserJet 8150 Series PS] printername: pubps7a3 set_printer_hnd_name: Printer found: pubps7 -> pubps7 [2010/08/17 15:47:12.785662, 5] rpc_server/srv_spoolss_nt.c:592(open_printer_hnd) 5 printer handles active [2010/08/17 15:47:12.785874, 4] rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal) Found policy hnd[0] [0000] 00 00 00 00 33 00 00 00 00 00 00 00 6A 4C DC 92 ....3... ....jL.. [0010] 81 4A 00 00 .J.. [2010/08/17 15:47:12.786770, 4] rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal) Found policy hnd[0] [0000] 00 00 00 00 33 00 00 00 00 00 00 00 6A 4C DC 92 ....3... ....jL.. [0010] 81 4A 00 00 .J.. [2010/08/17 15:47:12.787660, 4] rpc_server/srv_spoolss_nt.c:379(get_printer_snum) short name:pubps7 [2010/08/17 15:47:12.790306, 10] smbd/share_access.c:237(user_ok_token) user_ok_token: share pubps7 is ok for unix user nobody [2010/08/17 15:47:12.792243, 10] lib/util_seaccess.c:57(se_map_generic) se_map_generic(): mapped mask 0x20020008 to 0x00020008 [2010/08/17 15:47:12.792492, 10] lib/util_seaccess.c:57(se_map_generic) se_map_generic(): mapped mask 0x100f000c to 0x000f000c [2010/08/17 15:47:12.792735, 10] lib/util_seaccess.c:57(se_map_generic) se_map_generic(): mapped mask 0x100f000c to 0x000f000c [2010/08/17 15:47:12.792985, 4] printing/nt_printing.c:5724(print_access_check) access check was FAILURE [2010/08/17 15:47:12.793326, 3] rpc_server/srv_spoolss_nt.c:1713(_spoolss_OpenPrinterEx) access DENIED for printer open [2010/08/17 15:47:12.793536, 4] rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal) Found policy hnd[0] [0000] 00 00 00 00 33 00 00 00 00 00 00 00 6A 4C DC 92 ....3... ....jL.. [0010] 81 4A 00 00 .J.. [2010/08/17 15:47:12.794417, 4] rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal) Found policy hnd[0] [0000] 00 00 00 00 33 00 00 00 00 00 00 00 6A 4C DC 92 ....3... ....jL.. [0010] 81 4A 00 00 .J.. [2010/08/17 15:47:12.795312, 3] rpc_server/srv_lsa_hnd.c:258(close_policy_hnd) Closed policy [2010/08/17 15:47:12.795513, 1] ../librpc/ndr/ndr.c:251(ndr_print_function_debug) spoolss_OpenPrinterEx: struct spoolss_OpenPrinterEx out: struct spoolss_OpenPrinterEx handle : * handle: struct policy_handle handle_type : 0x00000000 (0) uuid : 00000000-0000-0000-0000-000000000000 result : WERR_ACCESS_DENIED [2010/08/17 15:47:12.796783, 5] rpc_server/srv_pipe.c:2467(api_rpcTNP) api_rpcTNP: called \spoolss successfully [2010/08/17 15:47:12.812881, 3] rpc_server/srv_pipe_hnd.c:343(free_pipe_context) free_pipe_context: destroying talloc pool of size 0 [2010/08/17 15:47:12.813147, 10] rpc_server/srv_pipe_hnd.c:776(write_to_internal_pipe) write_to_pipe: data_used = 188 [2010/08/17 15:47:12.813550, 6] rpc_server/srv_pipe_hnd.c:811(read_from_internal_pipe) name: \spoolss len: 1024 [2010/08/17 15:47:12.813800, 10] rpc_server/srv_pipe_hnd.c:870(read_from_internal_pipe) read_from_pipe: \spoolss: fault_state = 0 : data_sent_length = 0, prs_offset(&p->out_data.rdata) = 24. [2010/08/17 15:47:12.814116, 5] rpc_parse/parse_prs.c:89(prs_debug) 000000 smb_io_rpc_hdr hdr 0000 major : 05 0001 minor : 00 0002 pkt_type : 02 0003 flags : 03 0004 pack_type0: 10 0005 pack_type1: 00 0006 pack_type2: 00 0007 pack_type3: 00 0008 frag_len : 0030 000a auth_len : 0000 000c call_id : 000000c1 [2010/08/17 15:47:12.815728, 5] rpc_parse/parse_prs.c:89(prs_debug) 000010 smb_io_rpc_hdr_resp resp 0010 alloc_hint: 00000018 0014 context_id: 0000 0016 cancel_ct : 00 0017 reserved : 00 [2010/08/17 15:47:12.816621, 5] smbd/ipc.c:56(copy_trans_params_and_data) copy_trans_params_and_data: params[0..0] data[0..48] (align 0) [2010/08/17 15:47:12.816916, 5] lib/util.c:617(show_msg) [2010/08/17 15:47:12.817053, 5] lib/util.c:620(show_msg) size=104 smb_com=0x25 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51203 smb_tid=1 smb_pid=1064 smb_uid=101 smb_mid=20224 smt_wct=10 smb_vwv[ 0]= 0 (0x0) smb_vwv[ 1]= 48 (0x30) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 0 (0x0) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 48 (0x30) smb_vwv[ 7]= 56 (0x38) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=49 [2010/08/17 15:47:12.819010, 10] ../lib/util/util.c:278(_dump_data) [0000] 00 05 00 02 03 10 00 00 00 30 00 00 00 C1 00 00 ........ .0...... [0010] 00 18 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0020] 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 00 ........ ........ [0030] 00 . [2010/08/17 15:47:12.820908, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 102 [2010/08/17 15:47:12.821157, 6] smbd/process.c:1481(process_smb) got message type 0x0 of len 0x66 [2010/08/17 15:47:12.821392, 3] smbd/process.c:1483(process_smb) Transaction 1401 of length 106 (0 toread) [2010/08/17 15:47:12.821646, 5] lib/util.c:617(show_msg) [2010/08/17 15:47:12.821782, 5] lib/util.c:620(show_msg) size=102 smb_com=0xa2 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=51207 smb_tid=1 smb_pid=1064 smb_uid=101 smb_mid=20290 smt_wct=24 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]=57054 (0xDEDE) smb_vwv[ 2]= 4096 (0x1000) smb_vwv[ 3]= 5632 (0x1600) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]=40704 (0x9F00) smb_vwv[ 8]= 513 (0x201) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 0 (0x0) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 0 (0x0) smb_vwv[14]= 0 (0x0) smb_vwv[15]= 768 (0x300) smb_vwv[16]= 0 (0x0) smb_vwv[17]= 256 (0x100) smb_vwv[18]= 0 (0x0) smb_vwv[19]=16384 (0x4000) smb_vwv[20]=16384 (0x4000) smb_vwv[21]= 512 (0x200) smb_vwv[22]= 0 (0x0) smb_vwv[23]= 768 (0x300) smb_bcc=19 [2010/08/17 15:47:12.825134, 10] ../lib/util/util.c:278(_dump_data) [0000] 00 5C 00 73 00 70 00 6F 00 6F 00 6C 00 73 00 73 .\.s.p.o .o.l.s.s [0010] 00 00 00 ... [2010/08/17 15:47:12.826005, 3] smbd/process.c:1293(switch_message) switch message SMBntcreateX (pid 19073) conn 0x12618d8 [2010/08/17 15:47:12.826280, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2010/08/17 15:47:12.826517, 10] smbd/nttrans.c:487(reply_ntcreate_and_X) reply_ntcreate_and_X: flags = 0x16, access_mask = 0x2019f file_attributes = 0x0, share_access = 0x3, create_disposition = 0x1 create_options = 0x400040 root_dir_fid = 0x0, fname = spoolss [2010/08/17 15:47:12.826925, 4] smbd/nttrans.c:283(nt_open_pipe) nt_open_pipe: Opening pipe \spoolss. [2010/08/17 15:47:12.827165, 5] smbd/files.c:118(file_new) allocated file structure 3559, fnum = 7655 (4 used) [2010/08/17 15:47:12.827484, 4] rpc_server/srv_pipe_hnd.c:98(make_internal_rpc_pipe_p) Create pipe requested \spoolss [2010/08/17 15:47:12.827763, 10] rpc_server/srv_lsa_hnd.c:129(init_pipe_handle_list) init_pipe_handles: pipe_handles ref count = 4 for pipe \spoolss [2010/08/17 15:47:12.828071, 3] smbd/sec_ctx.c:209(push_sec_ctx) push_sec_ctx(60001, 60001) : sec_ctx_stack_ndx = 1 [2010/08/17 15:47:12.828346, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(101) : conn_ctx_stack_ndx = 0 [2010/08/17 15:47:12.828586, 3] smbd/sec_ctx.c:309(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2010/08/17 15:47:12.828840, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2010/08/17 15:47:12.829042, 5] auth/token_util.c:550(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups ^C [printsrv9] /global/spool/samba_logs # less it-xenvm026.printsrv9.smblog Cannot use lesskey file "/usr/local/lib/less.init" [2010/08/17 15:47:12.831044, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: maximum password age, val: -1 [2010/08/17 15:47:12.877149, 3] smbd/sec_ctx.c:417(pop_sec_ctx) pop_sec_ctx (60001, 60001) - sec_ctx_stack_ndx = 0 [2010/08/17 15:47:12.877441, 3] smbd/sec_ctx.c:209(push_sec_ctx) push_sec_ctx(60001, 60001) : sec_ctx_stack_ndx = 1 [2010/08/17 15:47:12.877714, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(101) : conn_ctx_stack_ndx = 0 [2010/08/17 15:47:12.877954, 3] smbd/sec_ctx.c:309(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2010/08/17 15:47:12.878209, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2010/08/17 15:47:12.878409, 5] auth/token_util.c:550(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2010/08/17 15:47:12.880362, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: password history, val: 0 [2010/08/17 15:47:12.880638, 3] smbd/sec_ctx.c:417(pop_sec_ctx) pop_sec_ctx (60001, 60001) - sec_ctx_stack_ndx = 0 [2010/08/17 15:47:12.880964, 10] passdb/pdb_get_set.c:607(pdb_set_username) pdb_set_username: setting username chbeyer, was [2010/08/17 15:47:12.881209, 10] passdb/pdb_get_set.c:630(pdb_set_domain) pdb_set_domain: setting domain WIN, was [2010/08/17 15:47:12.881448, 10] passdb/pdb_get_set.c:653(pdb_set_nt_username) pdb_set_nt_username: setting nt username chbeyer, was [2010/08/17 15:47:12.881695, 10] passdb/pdb_get_set.c:676(pdb_set_fullname) pdb_set_full_name: setting full name Beyer, Christoph, was [2010/08/17 15:47:12.881950, 10] passdb/pdb_get_set.c:769(pdb_set_homedir) pdb_set_homedir: setting home dir \\win.desy.de\home\chbeyer, was [2010/08/17 15:47:12.882208, 10] passdb/pdb_get_set.c:745(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive H:, was NULL [2010/08/17 15:47:12.882452, 10] passdb/pdb_get_set.c:699(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2010/08/17 15:47:12.882696, 10] passdb/pdb_get_set.c:722(pdb_set_profile_path) pdb_set_profile_path: setting profile path , was [2010/08/17 15:47:12.882947, 10] passdb/pdb_get_set.c:812(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2010/08/17 15:47:12.883198, 3] smbd/sec_ctx.c:209(push_sec_ctx) push_sec_ctx(60001, 60001) : sec_ctx_stack_ndx = 1 [2010/08/17 15:47:12.883471, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(101) : conn_ctx_stack_ndx = 0 ...skipping... smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=51207 smb_tid=1 smb_pid=65279 smb_uid=101 smb_mid=21573 smt_wct=3 smb_vwv[ 0]= 7655 (0x1DE7) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2010/08/17 15:47:17.956771, 3] smbd/process.c:1293(switch_message) switch message SMBclose (pid 19073) conn 0x12618d8 [2010/08/17 15:47:17.957027, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2010/08/17 15:47:17.957234, 3] smbd/reply.c:4632(reply_close) close fd=-1 fnum=7655 (numopen=1) [2010/08/17 15:47:17.957473, 6] smbd/close.c:501(set_close_write_time) close_write_time: Thu Jan 1 00:59:59 1970 [2010/08/17 15:47:17.957703, 10] rpc_server/srv_lsa_hnd.c:288(close_policy_by_pipe) close_policy_by_pipe: deleted handle list for pipe \spoolss [2010/08/17 15:47:17.957978, 5] smbd/files.c:496(file_free) freed files structure 7655 (0 used) [2010/08/17 15:47:17.958219, 5] lib/util.c:617(show_msg) [2010/08/17 15:47:17.958354, 5] lib/util.c:620(show_msg) size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51203 smb_tid=1 smb_pid=65279 smb_uid=101 smb_mid=21573 smt_wct=0 smb_bcc=0
Hi, you can close this one I got a patch that works for me... cheers christoph
Created attachment 5946 [details] Patch for 3.5 This is the patch btw. I'm still investigating the issue. The problem is that this seems to depend on configure options: With a plain ./configure;make (with some tweaking regarding stdbool etc) the problem does not occur, with advanced includes etc it breaks. Also: This code is *ANCIENT*. Why on earth has nobody found this yet??? Volker
Ok, found out what it is (at least I think so). We did not find this, because we usually use the system iconv for CP850. This works as long as CP850.c is compiled as a shared module. On this machine shared modules were disabled, thus we did not ask to init the system iconv. So it is a combination of big endian (SPARC) and disabling shared modules, apparently a very rare combination. Re-opening, so that it does not get lost for 3.5 Volker
Comment on attachment 5946 [details] Patch for 3.5 This is a wonderful catch - well done Volker ! Jeremy.
Re-assigning to Karolin for inclusion in 3.5.next. Jeremy.
Pushed to v3-5-test. Closing out bug report. Thanks!