Created attachment 7808 [details] Level 10 debug log We had running a printserver on 3.5.16 without problems. Then I switched to 3.6.7 (also happens with 3.6.6) and since that, the smbd.log is flooded with messages [2012/08/22 15:24:44.017670, 1] printing/printer_list.c:94(printer_list_get_printer) Failed to fetch record! This message is logged every minute. When I start smbd, then the log is flooded with over 100 of the following: [2012/08/22 15:21:24.057353, 0] rpc_client/cli_winreg_spoolss.c:241(winreg_printer_openkey) winreg_printer_openkey: Could not open HKLM hive: NT_STATUS_RPC_PROCNUM_OUT_OF_RANGE I don't know if this matters: The s3 server is running in a test environment connected to an s4 beta6 DC (we plan to migrate to s4 in 3 weeks). I attached a level 10 debug log of the first start of 3.6.7 (with the lock directory from 3.5.16). Please let me know if you need any further files/debug logs.
I saw, that it's not just the smbd.log. The message [2012/08/23 16:07:33.258953, 1] printing/printer_list.c:94(printer_list_get_printer) Failed to fetch record! is also logged every minute in every machine logfile (log file = /var/log/samba/%m.log). What causes really logfile flooding (i have "log level = 1" in my smb.conf).
The "Failed to fetch record!" messages every minute in every machine logfile also appears in our production environment (s3 only) after I upgraded our 3.5.17 file-/printserver to 3.6.7.
You don't use CUPS right?
We use LPRng 3.8.Arc4 (self compiled) on Scientific Linux 6.2 (RHEL clone).
Could you attach gdb, set a breakpoint in printer_list_get_printer() an get a backtrace. I think we call pcap_printername_ok() at a wrong location.
Can you please tell me, how I can create it for you? Sorry. I'm not a developer.
If you have 'debug pid = yes' in your smb.conf file, you will find the pid of the process in the log file. So search for the printing/printer_list.c:94(printer_list_get_printer) Failed to fetch record! and in the line above you should see the pid. Then do gdb -p <pid> break printer_list_get_printer continue As soon as printer_list_get_printer() is called it will stop, then type backtrace full and post the output here. You should do this with debug symbols :) quit to leave gdb
Created attachment 7836 [details] gdb output I recompiled with --enable-developer and --enable-debug and followed your steps. Hope this configure options bring the debug symbols. Find the gdb output attached.
This isn't the output I wanted. After attaching gdb and setting the breakpoint (was setting the breakpoint successfull?) did you type 'continue'? When you attach gdb the program is halted. You need to type continue start it resumes and can hit the breakpoint. You can also find me in #samba-technical on freenode as gladiac if you need more help.
Created attachment 7838 [details] v3-6-test patch
Comment on attachment 7838 [details] v3-6-test patch Looks good Andreas.
Karolin, could you please add this to the next 3.6 release? Thanks!
Oh, we did further debugging in a query and Marc tested the patch and confirmed that it is working.
Pushed to v3-6-test. Closing out bug report. Thanks!
*** Bug 9152 has been marked as a duplicate of this bug. ***
I've applied the patch and it has not seemed to work. I still get reams of "Failed to fetch record!" messages. I've supplied log level 10 entries between successive "Failed to fetch record!" log entries so hopefully that will give you enough context to figure out the problem.
Created attachment 7897 [details] Log level 10 message showing printer_list_get_printer problem
The message is not a bug! We should probably increase just the debug level for that message.
Thanks, that would work for me. The sheer volume of these log messages would mislead you into believing something is very wrong. What are these log entries trying tell to me anyways?
It tells you that the printcap cache is empty.
Created attachment 7909 [details] Bump printer_list_get_printer message to log level 3 A trivial patch to implement the above suggestion (I don't know what the appropriate log level should be, so I chose 3). This certainly has calmed down samba syslog entries as this hourly histogram shows 09/18 05:00 [ 961] xx 09/18 06:00 [ 961] xx 09/18 07:00 [ 2755] xxxxxx 09/18 08:00 [ 1154] xx 09/18 09:00 [ 8720] xxxxxxxxxxxxxxxxxxx 09/18 10:00 [12251] xxxxxxxxxxxxxxxxxxxxxxxxxx 09/18 11:00 [ 3187] xxxxxx 09/18 12:00 [ 9049] xxxxxxxxxxxxxxxxxxx 09/18 13:00 [ 6830] xxxxxxxxxxxxxx 09/18 14:00 [ 6403] xxxxxxxxxxxxx 09/18 15:00 [12913] xxxxxxxxxxxxxxxxxxxxxxxxxxxx 09/18 16:00 [ 5270] xxxxxxxxxxx 09/18 17:00 [ 1149] xx 09/18 18:00 [ 1689] xxx 09/18 19:00 [ 1713] xxx 09/18 20:00 [ 822] x 09/18 21:00 [ 642] x 09/18 22:00 [ 3423] xxxxxxx 09/18 23:00 [ 887] x 09/19 00:00 [ 0] <patched during the following hour> 09/19 01:00 [ 21] 09/19 02:00 [ 3] 09/19 03:00 [ 0] 09/19 04:00 [ 0] 09/19 05:00 [ 0]
Created attachment 7910 [details] Increase debug level of debug message. Followup patch to silence the log by increasing the debug level of the message telling you that the database doesn't contain a printer.
Comment on attachment 7910 [details] Increase debug level of debug message. looks good.
Karolin, could you please add the last patch which increases the debuglevel too. Thanks!
Pushed to v3-6-test and cherry-picked from master to autobuild-v4-0-test. Closing out bug report. Thanks!