I think I've found a strange behavior which is easy to reproduce (running macOS 10.15.4):
I have a kext which simply attaches to an IOService in the IO Registry.
My function start is like this:
bool MyAIC::start( IOService * provider )
{
IOLog("[ MyAIC::start11\n");
bool result = super::start( provider );
IOLog("] MyAIC::start\n");
return result;
}I update the number in the first IOLog after each update to make sure I know the correct code is working. It says "start11" now and will be "start12" next time.
I use the following to log output in Terminal.app:
log stream -style compact --info --predicate "message contains 'MyAIC'"I use the following install script to load a new version of the kext after building in Xcode:
cd /Volumes/Work/Programming/MyProjects/MyAIC
kextidentifier="com.joevt.driver.MyAIC"
kextname="MyAIC.kext"
kextsrcdir="DerivedData/MyAIC/Build/Products/Debug"
kexttmpdir="$(mktemp -d)"
kextinstalldir=/Library/Extensions
while ( kextstat | grep "$kextidentifier" ); do
sleep 1
sudo kextunload -b "$kextidentifier"
done
sudo cp -p -R "$kextsrcdir/$kextname" "$kexttmpdir/"
sudo chown -R root:wheel "$kexttmpdir/$kextname"
sudo find "$kexttmpdir/$kextname" -type d -exec /bin/chmod 0755 {} \;
sudo find "$kexttmpdir/$kextname" -type f -exec /bin/chmod 0644 {} \;
sudo kextutil "$kexttmpdir/$kextname"
kextstat | grep "$kextidentifier"
echo "done"After running the install script, the log in Terminal.app shows:
2020-05-21 00:09:11.879 E kernel[0:d7a8] (MyAIC) [ MyAIC::start11I use the following to check the code was compiled and copied properly:
strings "$kextsrcdir/$kextname/Contents/macOS/"* | egrep 'start[0-9]'
strings "$kexttmpdir/$kextname/Contents/macOS/"* | egrep 'start[0-9]'The result after the first time installing is:
[ MyAIC::start11
[ MyAIC::start11
[ MyAIC::start11
[ MyAIC::start11Now, while the log stream is still running in Terminal.app, I update the code and rebuild the kext so the log should show "start12". I execute the install script, but Terminal.app shows "start11" which means the kext was loaded from some copy located who knows where? I can repeat the install script multiple times and each time it shows "start11". I use the strings command to check that the code contains the "start12" string.
I have to stop and start the "log" in Terminal.app, then the next execution of the install script will show "start12". How does this make sense? What does "log" have to do with "kextutil"? Also, I have to stop and start the "log" after executing at least once the install script with the new kext. That means it takes two installs to get the new code to work.
Is there a command I can add to my install script to make it load the latest version of my kext properly?
Ok, now for something even more strange:
I have a macro for IOLog like this in my code:
#define IOLog(...) os_log_error(OS_LOG_DEFAULT, __VA_ARGS__)If I change the macro to use os_log instead of os_log_error, and I increase the start number, then build, then install, the log shows the old start number but shows Df for default instead of E for error. So it will pick up the change in the function call but not in the string text? Are the code and data sections handled (cached) differently?