Uploaded image for project: 'XenServer Org'
  1. XenServer Org
  2. XSO-553

debug logs outputting to /var/log/daemon.log and /var/log/xensource.log

    Details

    • Type: Bug
    • Status: Done (View Workflow)
    • Priority: Critical
    • Resolution: Done
    • Affects Version/s: 7.0, 7.1
    • Fix Version/s: 7.1
    • Component/s: other
    • Labels:

      Description

      It appears that debug level logs, mostly from 'squeezed' are ending up in /var/log/daemon.log.

      As I see it:

      • This is not what daemon.log is designed for (it's what /var/log/debug.log is designed for).
      • Debug level logging shouldn't be running by default on production hosts unless triggered by the user.
      • This fills up daemon.log with 'noise' which makes it hard to find actual daemon related logs which are especially important as XenServer 7 disables journalctl logging.
      [root@s1-b8 log]# grep debug xensource.log|tail -40
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |events|xenops_server] Received an event on managed VM 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |queue|xenops_server] Queue.push ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"] onto redirected 7df331fc-99af-1ed4-f6e6-30e6473d209b:[ ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"] ]
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |events|xenops_server] Received an event on managed VM 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |queue|xenops_server] Queue.push ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"] onto redirected 7df331fc-99af-1ed4-f6e6-30e6473d209b:[ ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"] ]
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |events|xenops_server] Received an event on managed VM 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |queue|xenops_server] Queue.push ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"] onto redirected 7df331fc-99af-1ed4-f6e6-30e6473d209b:[ ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"] ]
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |events|xenops_server] Received an event on managed VM 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |queue|xenops_server] Queue.push ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"] onto redirected 7df331fc-99af-1ed4-f6e6-30e6473d209b:[ ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"] ]
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|35 |events|xenops_server] VM 7df331fc-99af-1ed4-f6e6-30e6473d209b is not requesting any attention
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|35 |events|xenops_server] VM_DB.signal 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|35 |events|task_server] Task 84489 completed; duration = 0
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|35 ||xenops_server] TASK.signal 84489 (object deleted)
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|33 ||xenops_server] Queue.pop returned ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"]
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|33 |events|xenops_server] Task 84490 reference events: ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"]
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] Processing event: ["Vm", "7df331fc-99af-1ed4-f6e6-30e6473d209b"]
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] xenops event on VM 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|67325 |org.xen.xapi.xenops.classic events D:290602462f89|xenops_server] VM.stat 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|33 |events|xenops_server] VM 7df331fc-99af-1ed4-f6e6-30e6473d209b is not requesting any attention
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|33 |events|xenops_server] VM_DB.signal 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|33 |events|task_server] Task 84490 completed; duration = 0
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|33 ||xenops_server] TASK.signal 84490 (object deleted)
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |events|xenops_server] Received an event on managed VM 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|3 |queue|xenops_server] Queue.push ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"] onto 7df331fc-99af-1ed4-f6e6-30e6473d209b:[  ]
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|11 ||xenops_server] Queue.pop returned ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"]
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|11 |events|xenops_server] Task 84496 reference events: ["VM_check_state", "7df331fc-99af-1ed4-f6e6-30e6473d209b"]
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] xenopsd event: ignoring event for VM 7df331fc-99af-1ed4-f6e6-30e6473d209b: metadata has not changed
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] Processing event: ["Vm", "7df331fc-99af-1ed4-f6e6-30e6473d209b"]
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] xenops event on VM 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|67327 |org.xen.xapi.xenops.classic events D:290602462f89|xenops_server] VM.stat 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|11 |events|xenops_server] VM 7df331fc-99af-1ed4-f6e6-30e6473d209b is not requesting any attention
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|11 |events|xenops_server] VM_DB.signal 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|11 |events|task_server] Task 84496 completed; duration = 0
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|11 ||xenops_server] TASK.signal 84496 (object deleted)
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] xenopsd event: processing event for VM 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] Supressing VM.allowed_operations update because guest_agent data is largely the same
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] xenopsd event: Updating VM 7df331fc-99af-1ed4-f6e6-30e6473d209b domid 13 guest_agent
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] Processing event: ["Vm", "7df331fc-99af-1ed4-f6e6-30e6473d209b"]
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] xenops event on VM 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xenopsd-xc: [debug|s1-b8|67329 |org.xen.xapi.xenops.classic events D:290602462f89|xenops_server] VM.stat 7df331fc-99af-1ed4-f6e6-30e6473d209b
      Jun  1 12:24:08 s1-b8 xapi: [debug|s1-b8|447 |org.xen.xapi.xenops.classic events D:290602462f89|xenops] xenopsd event: ignoring event for VM 7df331fc-99af-1ed4-f6e6-30e6473d209b: metadata has not changed
      
      [root@s1-b8 log]# grep debug daemon.log|tail -40
      Jun  1 12:19:07 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:19:07 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:19:07 2016
      Jun  1 12:19:17 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:19:17 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:19:17 2016
      Jun  1 12:19:27 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:19:27 AEST 2016
      Jun  1 12:19:36 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:19:36 AEST 2016
      Jun  1 12:19:53 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:19:53 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:19:53 2016
      Jun  1 12:20:07 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:20:07 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:20:07 2016
      Jun  1 12:20:17 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:20:17 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:20:17 2016
      Jun  1 12:20:53 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:20:53 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:20:53 2016
      Jun  1 12:21:07 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:21:07 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:21:07 2016
      Jun  1 12:21:17 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:21:17 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:21:17 2016
      Jun  1 12:21:27 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:21:27 AEST 2016
      Jun  1 12:21:37 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:21:37 AEST 2016
      Jun  1 12:21:53 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:21:53 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:21:53 2016
      Jun  1 12:22:07 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:22:08 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:22:08 2016
      Jun  1 12:22:17 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:22:17 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:22:17 2016
      Jun  1 12:22:53 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:22:54 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:22:54 2016
      Jun  1 12:23:08 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:23:08 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:23:08 2016
      Jun  1 12:23:17 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:23:18 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:23:18 2016
      Jun  1 12:23:27 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:23:27 AEST 2016
      Jun  1 12:23:37 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:23:37 AEST 2016
      Jun  1 12:23:54 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:23:54 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:23:54 2016
      Jun  1 12:24:08 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:24:08 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:24:08 2016
      Jun  1 12:24:18 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /control/feature-balloon <- 1
      Jun  1 12:24:18 s1-b8 squeezed: [debug|s1-b8|3 ||xenops] watch /data/updated <- Wed Jun  1 12:24:18 2016
      

        Attachments

        1. sacrificial-space-for-logs.bz2
          0.1 kB
        2. xen-log-folder.txt
          5 kB
        3. xenlogs.tar.bz2
          20.01 MB
        4. xen-top.txt
          9 kB

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                s_mcleod Sam McLeod
              • Votes:
                0 Vote for this issue
                Watchers:
                8 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: