Dear Kevin, thank you!
This topic was caused by my experiment, that under the same work-flow the same USB2 gadgets (which FWs follows basic of SDKs CypEZFX2,CypEZFX3, AnDevBlackFn; follws closely enough, as far as I may "kenne maine Pappenheimers"...).
in Windows,Android,MACOSX behave as expecting;
in tested iPADgen5,gen6 have large delay between physical plugin and invocation of DExt's entry-points
Then I wrongly supposed that iPadOS16,17 needs to run UserClientBundle to trigger invocation of DExt's entry-points. Thanks to your clearance, the issue is "resolved" from the SW-point-of-view. From this point of view, iPadOS16,17 seemingly behavs completely|quite similar to MACOSX.
-- here is the summary to close this topic as "answered" --
"best answer_approach" is "timestamp of one of the two DExt's entry-points" (both entry-points are ~equivalent here):
class DExt: public IOUSBHostInterface { public: // -- file DExt.iig; IOUSBHostDevice wasn't tested within this scope
virtual bool init(void) override;
virtual kern_return_t Start( IOService *AProvider ) override;
... };
= Stipulation 1) This is answer for ~timeflow:
MAC/iPAD power_on
1st plugin of the gadget
1st-invocation of the enty-point
1st start of respective UserClentBundle.
This fixes the principal issue, when right_minded_user plugs warmup_need_gadget before start respective UserClientBundle.
= Stipulation 2) An instance of the "class DExt:" could be destroyed/re-created many times (either by unplug or by kill/termination of respective UserClentBundle).
= Stipulation 3) To fix timeflows with "Stipulation 2", UserClentBundle|EndUserApp should count:
it's own terminations
disconnection_events from it's own DExt.
= Stipulation 4) As an (plain) alternative for MACOSX only, EndUserApp might just enumerate|parse system_logs.
Post
Replies
Boosts
Views
Activity
The note to previous "long log":
"RyDD - init() - Succeed." appeared
<1 sec after physical plugin 1 time of 3
~10 sec after physical plugin 1 time of 3
~5 sec after physical plugin 1 time of 3
I shall confirm that (from the point of view of SW-logs):
MACOSX14 and iPADOS17 behave quite similar;
my previous experiment (wich shows those 're different) was "technical mistake";
manual start of my sample UserClient isn't "necessary in fact" in iPAD17 to trigger the invocation of "RyDD - init() -" of "activated DExt";
I shall note that "manual start of my sample UserClient avoids occasional huge delays with the invocation"; but this likely is HW-issue.
= Hence (this could be "best possible answer" at this moment):
I could keep timestamp of "RyDD - init() -" in my "Dext_Vars" and then pass it later to UserClient.
--- addition question ---
If such a subject could be treated as an "off-topic against the theme in starting message" then please ignore the following
I also shall appreciate if you may occasionally provide "extended comment" about:
what could be done to investigate possible cause of SW|HW-delays between physical plugin and invocation of "RyDD - init() -" in iPADgen5 M1 OS16, iPADgen6 M2 OS17 ?
--- end of addition question ---
Log in iPAD17 (section A)
DExt's entry points are called in this sample within <1sec after plugin (1 or 3 times). 2 of 3 times those are called >5 sec later.
Here are messages "change handling USB2<=>USB3" (the gadget is actually USB2)
efault 09:42:58.561261+0900 kernel IOAccessoryManagerUSBC::setLDCMPin(): ldcmPin: 2 [Trace]
default 09:42:58.561335+0900 kernel IOAccessoryManagerUSBC::setLDCMPin(): ldcmPin: 2 [Trace]
default 09:42:58.561851+0900 kernel IOPort::setLDCMState(): [Port-USB-C@1] setLDCMState: 3 [Measure]
default 09:42:58.683860+0900 kernel wlan0:com.apple.p2p: reportDataPathEvents[6702]: WiFi default 09:42:58.747963+0900 kernel IOPortTransportState::handleStateChange(): [Port-USB-C@1: USB3] Handling state change...
default 09:42:58.748028+0900 kernel IOServiceNotificationManager::sendMessages(): [Port-USB-C@1/USB3] Sending 2 message(s)... (m_propertyChanged: YES)
default 09:42:58.748210+0900 kernel IOPortTransportState::handleStateChange(): [Port-USB-C@1: USB2] Handling state change...
default 09:42:58.748275+0900 kernel IOServiceNotificationManager::sendMessages(): [Port-USB-C@1/USB2] Sending 1 message(s)... (m_propertyChanged: NO)
default 09:42:58.748367+0900 kernel IOAccessoryTRM::_processNotifications(): Processing notifications...
default 09:42:58.748836+0900 kernel IOAccessoryPowerSource::createPowerSourceItemsInternal(): id:0x100000797, owner=<private> tag=<private> itemSet=0x0 removeTagSet=0x0...
default 09:42:59.653465+0900 kernel IOPortTransportState::registerService(): [Port-USB-C@1: USB2] Registering service USB2@(null)... (transportType: 2, provider: Port-USB-C@1)
default 09:42:59.653496+0900 kernel IOPortTransportState::setNominalSignalingFrequencies(): [Port-USB-C@1: USB2] Setting nominal signaling frequencies... (nominalSignalingFrequenciesHz: YES, nominalSignalingFrequenciesHz.count: 3)
default 09:42:59.653729+0900 kernel IOServiceNotificationManager::sendMessages(): [Port-USB-C@1] Sending 2 message(s)... (m_propertyChanged: YES)
default 09:42:59.816095+0900 kernel IOPortTransportState::setNominalSignalingFrequencies(): [Port-USB-C@1: USB2] Setting nominal signaling frequencies... (nominalSignalingFrequenciesHz: YES, nominalSignalingFrequenciesHz.count: 1)
default 09:42:59.822846+0900 kernel usb-drd0-port-hs@00100000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x3488/0002/0100 (EzSensor XHD / 1) at 480 Mbps
default 09:42:59.822981+0900 kernel IOPortTransportState::handleMetadataChanges(): [Port-USB-C@1: USB2] Handling metadata changes... (shouldReregisterService: NO)
default 09:42:59.823014+0900 kernel IOPortTransportState::_updatePreDefinedMetadataProperties(): [Port-USB-C@1: USB2] Updating pre-defined metadata properties...
default 09:42:59.823106+0900 kernel IOServiceNotificationManager::handleServiceReregistration(): [Port-USB-C@1/USB2] Re-registering service...
default 09:42:59.823152+0900 kernel IOPortTransportState::registerService(): [Port-USB-C@1: USB2] Registering service USB2@(null)... (transportType: 2, provider: Port-USB-C@1)
default 09:42:59.823194+0900 kernel IOPortTransportState::setHash(): [Port-USB-C@1: USB2] hash: YES
default 09:42:59.823661+0900 kernel ACM: logRecord: acc-cache-check: unexpired record found: tm=1739493764 hash(32)=<8f5d391e3e776d68942e0bd0f157f256c0a55b61e3999a4324197b39d62ed982> data(4)=<02000000> group(16)=<b93f9cddbcce4141a11f8a22ba3f7290>.
default 09:42:59.823755+0900 kernel IOPortTransportState::_updateHashStatus_block_invoke(): [Port-USB-C@1: USB2] m_hashStatus: 0 -> 3 [Not Set -> Cached]
default 09:42:59.823868+0900 kernel ACM: logRecord: acc-cache-add: replacing existing record: tm=1739493764 hash(32)=<8f5d391e3e776d68942e0bd0f157f256c0a55b61e3999a4324197b39d62ed982> data(4)=<02000000> group(16)=<b93f9cddbcce4141a11f8a22ba3f7290>.
default 09:42:59.823904+0900 kernel ACM: logRecord: acc-cache-add: adding record: tm=1739493780 hash(32)=<8f5d391e3e776d68942e0bd0f157f256c0a55b61e3999a4324197b39d62ed982> data(4)=<02000000> group(16)=<42f12b200cf1442b84aad85be16fce1d>.
default 09:42:59.824063+0900 kernel ACMTRM-S: setData: saving *acc-cache* (dataLen=5384) in 3 seconds (fullSync: NO -> NO).
default 09:42:59.824166+0900 kernel ACM: logRecord: acc-cache-check: unexpired record found: tm=1739493780 hash(32)=<8f5d391e3e776d68942e0bd0f157f256c0a55b61e3999a4324197b39d62ed982> data(4)=<02000000> group(16)=<42f12b200cf1442b84aad85be16fce1d>.
default 09:42:59.824256+0900 kernel IOPortTransportState::_updateTRMState(): [Port-USB-C@1: USB2] Updating TRM state...
default 09:42:59.824287+0900 kernel IOPortTransportStateUSB::calculateAuthorizationState(): [Port-USB-C@1: USB2] Calculating authorization state...
default 09:42:59.824316+0900 kernel IOPortTransportState::calculateAuthorizationState(): [Port-USB-C@1: USB2] Calculating authorization state...
default 09:42:59.824369+0900 kernel IOPortTransportState::calculateAuthorizationState_block_invoke(): [Port-USB-C@1: USB2] *** UNRT ***
default 09:42:59.824516+0900 kernel IOServiceNotificationManager::sendMessages(): [Port-USB-C@1/USB2] Sending 2 message(s)... (m_propertyChanged: YES)
default 09:42:59.824706+0900 kernel AppleNotificationQueue::processNotifications(): Processing 1 notification(s)...
default 09:42:59.824755+0900 kernel AppleNotificationQueue::_handleNotifications(): Handling notifications...
default 09:42:59.827337+0900 kernel AppleUSBHostResourcesTypeC@(null): AppleUSBHostResourcesTypeC::allocateDownstreamBusCurrentGated: Client <private> is requesting 500mA wake and 0mA sleep for port 0
default 09:42:59.827435+0900 kernel AppleUSBHostResourcesTypeC@(null): AppleUSBHostResourcesTypeC::allocateDownstreamBusCurrentGated: Client <private> port 0 has EDT current overrides of 1500mA wake and 1500mA sleep
default 09:42:59.827474+0900 kernel AppleUSBHostResourcesTypeC@(null): AppleUSBHostResourcesTypeC::allocateDownstreamBusCurrentGated: Granting 500mA wake and 0mA sleep based on override for port 0
default 09:42:59.827514+0900 kernel EzSensor XHD@00100000: IOUSBHostDevice::setConfigurationGated: AppleUSBHostCompositeDevice selected configuration 1
default 09:42:59.837877+0900 kernel Driver com.rayence.dextsample.driver has crashed 4 time(s)
default 09:42:59.837935+0900 kernel DK: DExt-0x100000e30 waiting for server com.rayence.dextsample.driver-100000e30
default 09:42:59.859193+0900 kernel /private/var/db/driverkitd/SystemExtensions/9F631B30-94C9-49DE-8BB5-04D342370774/com.rayence.dextsample.driver.dext/com.rayence.dextsample.driver[481] ==> com.apple.dext
default 09:42:59.868133+0900 kernel DK: com.rayence.dextsample.driver[481] has team identifier PZEDDMJXDA
default 09:42:59.868340+0900 kernel <private>
…
default 09:42:59.869858+0900 kernel <private>
default 09:42:59.870840+0900 kernel RyDD - init() - Succeed.
default 09:42:59.870851+0900 kernel RyDD - Start() - Succeed
Dear Kevin, after your message I repeated check 1 time in MAC and 3 times in iPAD. I see possible clue of the difference between MACBook and iPAD17.
MACBook
default 09:16:03.095874+0900 kernel LQM-WIFI: (HighBand) rxNotPrimary20s=0 ucodeLateDrop=0 rxInvalidUcodeLateWrongMACPHY=0 rxLate30us=0 rxLegacyFrmInvalid=0 txSifsErr=0 ooseqMacSusp=0
default 09:16:03.101392+0900 kernel LQM-WIFI: Dynamic BW Stats: TxRTS [0, 0, 0, 0] RxRTS [0, 0, 0, 0] TxCTS [0, 0, 0, 0] RxCTS [0, 0, 0, 0]
default 09:16:03.101408+0900 kernel LQM-WIFI: Dynamic BW Stats: TxMPDU [0, 0, 0, 0] RxMPDU [0, 0, 0, 0]
default 09:16:03.487406+0900 kernel LQM-WIFI-CT: ofdmDesense=0 bphyDesense=0 reason=0x0
default 09:16:05.906054+0900 kernel AppleUSB20HubPort@01143000: AppleUSBHostPort::enumerateDeviceComplete_block_invoke: enumerated 0x3488/0002/0100 (EzSensor XHD / 5) at 480 Mbps
default 09:16:05.909537+0900 kernel EzSensor XHD@01143000: IOUSBHostDevice::setConfigurationGated: AppleUSBHostCompositeDevice selected configuration 1
default 09:16:05.917779+0900 kernel Driver com.rayence.dextsample.driver has crashed 0 time(s)
default 09:16:05.917843+0900 kernel DK: DExt-0x100000f10 waiting for server com.rayence.dextsample.driver-100000f10
default 09:16:05.919192+0900 kernelmanagerd Found 1 dexts with bundle identifier com.rayence.dextsample.driver
default 09:16:05.919435+0900 kernelmanagerd Using unique id 41cecb3133c7084f322eefd5b38f4fc3b3a7b52b7053d3746b2324423b9eab86 to pick dext matching bundle identifier com.rayence.dextsample.driver
default 09:16:05.920672+0900 kernelmanagerd Picked matching dext for bundle identifier com.rayence.dextsample.driver: Dext com.rayence.dextsample.driver v1 in executable dext bundle com.rayence.dextsample.driver at /Library/SystemExtensions/CACFB48B-C6D6-46D2-8D74-5FA4C7802E4A/com.rayence.dextsample.driver.dext
default 09:16:05.921375+0900 kernelmanagerd DextRecordTable read from plist: {
// — manual note: I have 2 ~identical <by the binaries> DExts in 2 SDK-sample bundles
// — com.rayence.dexta.driver - SDK-project#1
// — com.rayence.dextsample.driver - SDK-project#2
// — everything works without a conflicts or a quirk
// — technically I don’t care which of my DExts initializes 1st, which 2nd in this workflow (as IOKITmatching always is logical)
com.rayence.dexta.driver:
MRS-> Optional(( path: /Library/SystemExtensions/304D47CF-904A-44D5-992C-332B013492D8/com.rayence.dexta.driver.dext; state: loaded ))
history-> [
( path: /Library/SystemExtensions/304D47CF-904A-44D5-992C-332B013492D8/com.rayence.dexta.driver.dext; state: loaded )
]
com.rayence.dextsample.driver:
MRS-> Optional(( path: /Library/SystemExtensions/CACFB48B-C6D6-46D2-8D74-5FA4C7802E4A/com.rayence.dextsample.driver.dext; state: loaded ))
history-> [
( path: /Library/SystemExtensions/CACFB48B-C6D6-46D2-8D74-5FA4C7802E4A/com.rayence.dextsample.driver.dext; state: loaded )
]
org.pqrs.Karabiner-DriverKit-VirtualHIDDevice:
MRS-> Optional(( path: /Library/SystemExtensions/59623BBE-793E-4E5C-B153-9DACFDA66EBC/org.pqrs.Karabiner-DriverKit-VirtualHIDDevice.dext; state: loaded ))
history-> [
( path: /Library/SystemExtensions/59623BBE-793E-4E5C-B153-9DACFDA66EBC/org.pqrs.Karabiner-DriverKit-VirtualHIDDevice.dext; state: loaded )
]
}
default 09:16:05.921588+0900 kernelmanagerd Launching driver extension: Dext com.rayence.dextsample.driver v1 in executable dext bundle com.rayence.dextsample.driver at /Library/SystemExtensions/CACFB48B-C6D6-46D2-8D74-5FA4C7802E4A/com.rayence.dextsample.driver.dext
default 09:16:05.933078+0900 kernel /Library/SystemExtensions/CACFB48B-C6D6-46D2-8D74-5FA4C7802E4A/com.rayence.dextsample.driver.dext/com.rayence.dextsample.driver[849] ==> com.apple.dext
default 09:16:05.933408+0900 kernelmanagerd <OSLaunchdJob | handle=6B6CE5C2-010E-4309-9140-F7EE365E3D74>: submitAndStart completed, info=running, pid=849
default 09:16:05.933603+0900 kernelmanagerd Received kext load notification: com.rayence.dextsample.driver
default 09:16:05.935569+0900 kernel <private>
…
default 09:16:05.936737+0900 kernel <private>
default 09:16:05.937925+0900 kernel RyDD - init() - Succeed.
default 09:16:05.937949+0900 kernel RyDD - Start() - Succeed
default 09:16:05.937967+0900 kernel DK:
…
Log of a "smooth run" of iPAD17 in the next message.
clearance_addition to the topic "in fact 2a)":
file DExt.iig
class DExt: public IOUSBHostInterface { public: // IOUSBHostDevice|Interface
virtual bool init(void) override;
virtual kern_return_t Start( IOService *AProvider ) override;
....
= 1) Dear Kevin, after my brief re-check it looks your following statement is 100% wrong in practice:
"he behavior here is actually identical on macOS and iOS. That is, when any device IOKit matching occurs which, in the case of a DEXT, means that your DEXT is eventually loaded and begins executing. Note that DEXT loading is in fact just a specific variation on the IOKit matching process, with the difference being that the IOKit driver your DEXT matching dictionary specified was designed to use the DEXT specific keys to match and interact with your out of kernel DEXT."
= 2) In fact
= 2a) In fact the code DExt.cpp:
#define Log(fmt, ...) os_log( OS_LOG_DEFAULT, "RyDD - " fmt "\n", ##__VA_ARGS__ )
bool DExt::init(void) { .... Log( "init() - Succeed." ); return true; }
kern_return_t DExt::Start_Impl( IOService *AProvider ) { ... Log( "Start() - Succeed" ); return kIOReturnSuccess; }
= 2b) In fact the console's output (without any active of my process !; fillter "RyDD" ); MAC BOOK M3; MAC OS 14; after power on and plug/unplug a gadget (my DExt is activated)
default 09:46:06.893553+0900 kernel RyDD - init() - Succeed.
default 09:46:06.893573+0900 kernel RyDD - Start() - Succeed
default 09:46:06.906789+0900 kernel RyDD - init() - Succeed.
default 09:46:06.906810+0900 kernel RyDD - Start() - Succeed```
= 2c) In fact the console's output in iPAD gen5,gen6
nothing (only system logs about USB gadget with certain PID/VID is connected)
= 3) Before talk about further topics we need establish and explain this fact.
Thanks a lot... though...
_"What's you're communication channel with your DEXT"
"What I would actually do is have your DEXT export this data as a property"
=1) Of course, as any normal programmer, I start any my SW-project from code to save/archive/trace any occasionally required DExt's/UserClient's-datas/events at any moment as properties/keys "[] MyKey=my_value" in Windows-INI-file-format:)
=2) MACOSX14 calls my DExt when I plug one of VID_????,PID_???? (declared in info.plist)
=2a) I easily trace plug events through my short INI-files (and duplicate those via unified Swift's log)
=2b) correct handling of plug/unplug in MAC needs just recording/archiving single value ~"TimeStamp>0" for connected gadget.
=2c) As/if I have my paranoid doubts then I easily & programmatically enumerate relevant system plug-logs (during recent 2..4 hours) via unified Swift log ".system" .
= 3) iPADOS16,17 seemingy has the "physical architectural problem"
= 3a) doesn't call any entry-point in my DExt when I connect relevant VID_????,PID_???? _(unless my UserClient was started manually in advance and is still alive)
= 3b) system log is simply not available programmatically.
= 3c) btw my UserClient's logs from older processID _(from previous sessions) also aren't available (though this is insignificant as I have INI-files to archive/trace logs)
= 4) The fundamental question is that I don't see "any physical/theoretical opportunity to know about plug in iPADOS16/17 _(unless my UserClient is explictly and manually started by the user).
But users normally perer plugin a gadget and then start UserClient in iPAD...
It 100% doesn't work in any straight forward manner:
"At the project level, you can create different configurations, e.g. Debug (iPad) and Debug (macOS), use .xcconfig files to change the few things that may need to change between macOS and iPadOS, for example the bundle ID of the driver."
Debug/Release can't be a matter in this topic. Signing seemingly has no relation to configs. Signing depends on "toolchain".
In available XCode15,
using (recommended) "automatic code signing",
switch between
"Apple-developer" (when I build for iPAD)
and
"Ad-hoc-code signing" (when I build for MAC)
works only in IDE.
In the dictionary of XCode-15-IDE,
for development-convenience
I would like to have an opportunity ~automatically assign
-"Ad-Hoc-signing" when target is "macOS"
~ "Apple-development" when target is "anything else"
Thank you :)
Right now: - I'm building "for developing".
Three months later: - "for communicating with End-User-Apps-developers of ... of "various backgrounds"
The situation:
I see "non-logical logs" of USB-gadget-attachment in "Console.app"; though that app is obviously buggy and "really misses messages", timing of certain "logs' in my tests look "non-logical" (so I am suspecting/expecting huge bugs in the core of OS development)
such bugs aren't fatal; but those shall be "stable bugs~=features"
but to treat (potential) system-bugs (or my bugs andOS quirks) as "features" I would prefer to have the same (as much as possible) "binaries with resources" at "development" and at "distribution"