10 Replies
      Latest reply on Jan 5, 2020 1:47 AM by eskimo
      liang.zhou Level 1 Level 1 (0 points)

        I use printf() in my kernel extension to print some debug logs. When the message is a bit long(beyond 300 characters, I'm not sure the exact length), it will not be shown in Console.app. To shrink the message a little bit, it can be shown successfully. Is there any limit on the message length in the kernel? I'm using macOS 10.14.6. Thanks!

        • Re: printf in kernel extension
          eskimo Apple Staff Apple Staff (12,675 points)

          Is there any limit on the message length in the kernel?

          Yes.  The kernel’s printf implementation has numerous limitations.

          If you’re serious about logging from the kernel, you should use the <os/log.h> API / KPI.  Be aware, however, that this also has limitations when called from the kernel.

          Share and Enjoy

          Quinn “The Eskimo!”
          Apple Developer Relations, Developer Technical Support, Core OS/Hardware
          let myEmail = "eskimo" + "1" + "@apple.com"

            • Re: printf in kernel extension
              liang.zhou Level 1 Level 1 (0 points)

              I try to use os_log instead of printf in my code, but no log can be shown in the Console.app.

              os_log(OS_LOG_DEFAULT, "some message";

               

              When I use the %s specifier, another problem occurs.

              os_log(OS_LOG_DEFAULT, "some message %s", cstringVar);

               

              I got this warning from Xcode:

              Invalid conversion specifier 's'

               

              Changing %s to %{public}s also doesn't work.

               

              So what is the correct way to use unified logging in a pure c environment? Thanks!

                • Re: printf in kernel extension
                  eskimo Apple Staff Apple Staff (12,675 points)

                  So what is the correct way to use unified logging in a pure c environment?

                  To be clear, we’re talking about a pure C environment within a KEXT, right?

                  I got this warning from Xcode:

                  Hmm, that’s strange.  I did something similar here and it worked as expected.  Specifically:

                  1. Using Xcode 11.1 on macOS 10.14.6, I created a new project using the Generic Kernel Extension template.

                  2. In xxx.c (where xxx is the name of the KEXT), I added an include to the top, just under the existing include:

                    #include <os/log.h>

                    .

                  3. I then added the following to xxx_start:

                    const char * cStringVar = "Hello Cruel World!";
                    os_log(OS_LOG_DEFAULT, "%s", cStringVar);

                    .

                  It compiles just fine.

                  Share and Enjoy

                  Quinn “The Eskimo!”
                  Apple Developer Relations, Developer Technical Support, Core OS/Hardware
                  let myEmail = "eskimo" + "1" + "@apple.com"

                    • Re: printf in kernel extension
                      liang.zhou Level 1 Level 1 (0 points)

                      I'm using Xcode 10.3 with macOS 10.12 SDK on 10.14.6. The os_log* functions is available in the SDK, but my kext cannot print any log on my own computer, even if I just print a literal C string. I've not yet tried it on 10.12 & 10.13.

                        • Re: printf in kernel extension
                          eskimo Apple Staff Apple Staff (12,675 points)

                          I'm using Xcode 10.3 … on 10.14.6.

                          FYI, I repeated the test above with Xcode 10.3 and it works as expected.

                          with macOS 10.12 SDK

                          Huh?  Xcode 10.3 ships with the 10.14 SDK.  Using it with any other SDK is unsupported and will result in weird bugs.

                          Note that os_log is one area where the SDK and toolchain must be well aligned because it uses compiler smarts to optimise the way that the format string gets included in the log.

                          Share and Enjoy

                          Quinn “The Eskimo!”
                          Apple Developer Relations, Developer Technical Support, Core OS/Hardware
                          let myEmail = "eskimo" + "1" + "@apple.com"

                            • Re: printf in kernel extension
                              FoamyDust Level 1 Level 1 (0 points)

                              Hey eksimo,

                               

                              thanks for looking into this. I ran across this same issue today, while working on a fun kext project. Specifically, the code compiles, but I haven't been able to confirm that the log message ends up somewhere retrievable.

                               

                              I'm on:

                              * macOS: 10.14.6 (18G1012)

                              * XCode: Version 11.2.1 (11B500)

                              * kext's macOS Deployment Target: 10.14

                               

                              I compiled a kext that contains:

                               

                              kern_return_t mydemo_start(kmod_info_t * ki, void *d)
                              {
                                  const char * cStringVar = "Hello Cruel World!";
                                  os_log(OS_LOG_DEFAULT, "%s", cStringVar);
                                  return KERN_SUCCESS;
                              }
                              

                               

                              kext seems to load fine, and it's displayed in kextstat, however log show --predicate 'eventMessage contains "Hello Cruel"' --info doesn't return any messages .

                               

                              Any ideas?

                                • Re: printf in kernel extension
                                  FoamyDust Level 1 Level 1 (0 points)

                                  Restarting macOS actually made this work. I suspect I had previously send pointer to bad data, which may have messed up some kext-related logging until restart. I haven't achieved clarity on when it stops working but sometimes, os_log from a kext reliably stops working.

                                   

                                  os_log_create also seems to reliably not work from a kext -- no subsystem or cateogry is passed with the associate message:

                                   

                                   

                                  os_log_t general_log = os_log_create("io.myname.test", "general");
                                  os_log(general_log, "hi there");
                                  IOLog("hello from cland v5");
                                  
                                  

                                  but

                                   

                                  $ log show --predicate 'senderImagePath contains "myname"' --last 5m --info --debug --style json
                                  Filtering the log data using "senderImagePath CONTAINS "happy""
                                  [{
                                    "traceID" : 17081085460484,
                                    "eventMessage" : "hi there",
                                    "eventType" : "logEvent",
                                    "source" : null,
                                    "formatString" : "hi there",
                                    "activityIdentifier" : 0,
                                    "subsystem" : "",              # <<<<<<< should not be empty
                                    "category" : "",               # <<<<<<< should not be empty
                                    "threadID" : 89482,
                                    "senderImageUUID" : "6CE18218-3F80-3215-A933-3F824337FC45",
                                    "backtrace" : {
                                      "frames" : [
                                        {
                                          "imageOffset" : 3883,
                                          "imageUUID" : "6CE18218-3F80-3215-A933-3F824337FC45"
                                        }
                                      ]
                                    },
                                    "processImagePath" : "\/kernel",
                                    "senderImagePath" : "\/Users\/myname\/kext\/sample.kext\/Contents\/MacOS\/happymeowmeow",
                                    "timestamp" : "2019-12-09 20:58:10.361445-0800",
                                    "machTimestamp" : 2232376941776,
                                    "messageType" : "Default",
                                    "processImageUUID" : "DFB5D0E2-3B41-3647-A48B-D704AFCC06B4",
                                    "processID" : 0,
                                    "senderProgramCounter" : 3883,
                                    "parentActivityIdentifier" : 0,
                                    "timezoneName" : ""
                                    • Re: printf in kernel extension
                                      eskimo Apple Staff Apple Staff (12,675 points)

                                      Thanks for the update.  Most interesting.

                                      Restarting macOS actually made this work.

                                      Weird.

                                      I haven't achieved clarity on when it stops working but sometimes, os_log from a kext reliably stops working.

                                      I got nothing )-:

                                      If you can come up with even a vague theory about reproducing this, please file a bug about it, posting your bug number, just for the record.

                                      os_log_create also seems to reliably not work from a kext

                                      That is expected (alas).

                                      Share and Enjoy

                                      Quinn “The Eskimo!”
                                      Apple Developer Relations, Developer Technical Support, Core OS/Hardware
                                      let myEmail = "eskimo" + "1" + "@apple.com"

                                        • Re: printf in kernel extension
                                          omgalvan Level 1 Level 1 (0 points)

                                          > That is expected (alas).

                                           

                                          Why? Where is this documented?

                                           

                                          I don't see how it's acceptable that stuff just "doesn't work", without further explanation.

                                           

                                          > Note that os_log is one area where the SDK and toolchain must be well aligned because it uses compiler smarts to optimise the way that the format string gets included in the log.

                                           

                                          Again, where is this documented?

                                           

                                          Some of us are using older SDKs because it's the recommended practice when supporting older macOS versions (see e.g. https://stackoverflow.com/a/15092753/3688293). I don't understand how a simple logging function can have bugs because of this.

                                            • Re: printf in kernel extension
                                              eskimo Apple Staff Apple Staff (12,675 points)

                                              Some of us are using older SDKs

                                              Are you working in the kernel?  Because the post you referenced is very much focused on user-space code (it has no mention of kernel, kext, or KPI).

                                              Share and Enjoy

                                              Quinn “The Eskimo!”
                                              Apple Developer Relations, Developer Technical Support, Core OS/Hardware
                                              let myEmail = "eskimo" + "1" + "@apple.com"