Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer

[kbuild test robot <lkp@intel.com>]

[-- Attachment #1: Type: text/plain, Size: 6712 bytes --]

Hi Hans,

I love your patch! Yet something to improve:

[auto build test ERROR on linus/master]
[also build test ERROR on v4.19-rc2 next-20180906]
[if your patch is applied to the wrong git tree, please drop us a note to help improve the system]

url:    https://github.com/0day-ci/linux/commits/Hans-de-Goede/printk-For-early-boot-messages-check-loglevel-when-flushing-the-buffer/20180906-215356
config: parisc-allnoconfig (attached as .config)
compiler: hppa-linux-gnu-gcc (Debian 7.2.0-11) 7.2.0
reproduce:
        wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
        chmod +x ~/bin/make.cross
        # save the attached .config to linux build tree
        GCC_VERSION=7.2.0 make.cross ARCH=parisc 

All errors (new ones prefixed by >>):

   kernel/printk/printk.c: In function 'console_unlock':
>> kernel/printk/printk.c:2377:5: error: implicit declaration of function 'suppress_message_printing' [-Werror=implicit-function-declaration]
        suppress_message_printing(msg->level))) {
        ^~~~~~~~~~~~~~~~~~~~~~~~~
   cc1: some warnings being treated as errors

vim +/suppress_message_printing +2377 kernel/printk/printk.c

  2297	
  2298	/**
  2299	 * console_unlock - unlock the console system
  2300	 *
  2301	 * Releases the console_lock which the caller holds on the console system
  2302	 * and the console driver list.
  2303	 *
  2304	 * While the console_lock was held, console output may have been buffered
  2305	 * by printk().  If this is the case, console_unlock(); emits
  2306	 * the output prior to releasing the lock.
  2307	 *
  2308	 * If there is output waiting, we wake /dev/kmsg and syslog() users.
  2309	 *
  2310	 * console_unlock(); may be called from any context.
  2311	 */
  2312	void console_unlock(void)
  2313	{
  2314		static char ext_text[CONSOLE_EXT_LOG_MAX];
  2315		static char text[LOG_LINE_MAX + PREFIX_MAX];
  2316		unsigned long flags;
  2317		bool do_cond_resched, retry;
  2318	
  2319		if (console_suspended) {
  2320			up_console_sem();
  2321			return;
  2322		}
  2323	
  2324		/*
  2325		 * Console drivers are called with interrupts disabled, so
  2326		 * @console_may_schedule should be cleared before; however, we may
  2327		 * end up dumping a lot of lines, for example, if called from
  2328		 * console registration path, and should invoke cond_resched()
  2329		 * between lines if allowable.  Not doing so can cause a very long
  2330		 * scheduling stall on a slow console leading to RCU stall and
  2331		 * softlockup warnings which exacerbate the issue with more
  2332		 * messages practically incapacitating the system.
  2333		 *
  2334		 * console_trylock() is not able to detect the preemptive
  2335		 * context reliably. Therefore the value must be stored before
  2336		 * and cleared after the the "again" goto label.
  2337		 */
  2338		do_cond_resched = console_may_schedule;
  2339	again:
  2340		console_may_schedule = 0;
  2341	
  2342		/*
  2343		 * We released the console_sem lock, so we need to recheck if
  2344		 * cpu is online and (if not) is there at least one CON_ANYTIME
  2345		 * console.
  2346		 */
  2347		if (!can_use_console()) {
  2348			console_locked = 0;
  2349			up_console_sem();
  2350			return;
  2351		}
  2352	
  2353		for (;;) {
  2354			struct printk_log *msg;
  2355			size_t ext_len = 0;
  2356			size_t len;
  2357	
  2358			printk_safe_enter_irqsave(flags);
  2359			raw_spin_lock(&logbuf_lock);
  2360			if (console_seq < log_first_seq) {
  2361				len = sprintf(text, "** %u printk messages dropped **\n",
  2362					      (unsigned)(log_first_seq - console_seq));
  2363	
  2364				/* messages are gone, move to first one */
  2365				console_seq = log_first_seq;
  2366				console_idx = log_first_idx;
  2367			} else {
  2368				len = 0;
  2369			}
  2370	skip:
  2371			if (console_seq == log_next_seq)
  2372				break;
  2373	
  2374			msg = log_from_idx(console_idx);
  2375			if ((msg->flags & LOG_NOCONS) ||
  2376			    ((msg->flags & LOG_CHK_LEVEL) &&
> 2377					suppress_message_printing(msg->level))) {
  2378				/*
  2379				 * Skip record if !ignore_loglevel, and
  2380				 * record has level above the console loglevel.
  2381				 */
  2382				console_idx = log_next(console_idx);
  2383				console_seq++;
  2384				goto skip;
  2385			}
  2386	
  2387			len += msg_print_text(msg,
  2388					console_msg_format & MSG_FORMAT_SYSLOG,
  2389					text + len,
  2390					sizeof(text) - len);
  2391			if (nr_ext_console_drivers) {
  2392				ext_len = msg_print_ext_header(ext_text,
  2393							sizeof(ext_text),
  2394							msg, console_seq);
  2395				ext_len += msg_print_ext_body(ext_text + ext_len,
  2396							sizeof(ext_text) - ext_len,
  2397							log_dict(msg), msg->dict_len,
  2398							log_text(msg), msg->text_len);
  2399			}
  2400			console_idx = log_next(console_idx);
  2401			console_seq++;
  2402			raw_spin_unlock(&logbuf_lock);
  2403	
  2404			/*
  2405			 * While actively printing out messages, if another printk()
  2406			 * were to occur on another CPU, it may wait for this one to
  2407			 * finish. This task can not be preempted if there is a
  2408			 * waiter waiting to take over.
  2409			 */
  2410			console_lock_spinning_enable();
  2411	
  2412			stop_critical_timings();	/* don't trace print latency */
  2413			call_console_drivers(ext_text, ext_len, text, len);
  2414			start_critical_timings();
  2415	
  2416			if (console_lock_spinning_disable_and_check()) {
  2417				printk_safe_exit_irqrestore(flags);
  2418				return;
  2419			}
  2420	
  2421			printk_safe_exit_irqrestore(flags);
  2422	
  2423			if (do_cond_resched)
  2424				cond_resched();
  2425		}
  2426	
  2427		console_locked = 0;
  2428	
  2429		/* Release the exclusive_console once it is used */
  2430		if (unlikely(exclusive_console))
  2431			exclusive_console = NULL;
  2432	
  2433		raw_spin_unlock(&logbuf_lock);
  2434	
  2435		up_console_sem();
  2436	
  2437		/*
  2438		 * Someone could have filled up the buffer again, so re-check if there's
  2439		 * something to flush. In case we cannot trylock the console_sem again,
  2440		 * there's a new owner and the console_unlock() from them will do the
  2441		 * flush, no worries.
  2442		 */
  2443		raw_spin_lock(&logbuf_lock);
  2444		retry = console_seq != log_next_seq;
  2445		raw_spin_unlock(&logbuf_lock);
  2446		printk_safe_exit_irqrestore(flags);
  2447	
  2448		if (retry && console_trylock())
  2449			goto again;
  2450	}
  2451	EXPORT_SYMBOL(console_unlock);
  2452	

---
0-DAY kernel test infrastructure                Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all                   Intel Corporation

[-- Attachment #2: .config.gz --]
[-- Type: application/gzip, Size: 4784 bytes --]