Can you reproduce this occurring? How?

usbi_get_monotonic_time() is supposed to return monotonically increasing time. It should be impossible for a subsequent call to give anearlier time. If somehow it does, the root cause should be investigated. I don't think just adding a check like you've done is the right solution.

Can you reproduce this occurring? How?

usbi_get_monotonic_time() is supposed to return monotonically increasing time. It should be impossible for a subsequent call to give anearlier time. If somehow it does, the root cause should be investigated. I don't think just adding a check like you've done is the right solution.

I will show you the test code with added logging and the reproduced logs. You will understand once you see them. This is not related to monotonicity.

I tested using the xusb example in conjunction with a USB flash drive.

libusb_debug_log.txt

....structtimespecnow;usbi_get_monotonic_time(&now);longdelta_sec=now.tv_sec-start.tv_sec;longdelta_nsec=now.tv_nsec-start.tv_nsec;if (delta_nsec<0) {usbi_err(ctx,"zg: s(%ld %ld) e(%ld %ld)",start.tv_sec,start.tv_nsec,now.tv_sec,now.tv_nsec);usbi_err(ctx,"zg: delta_sec %ld delta_nsec %ld",delta_sec,delta_nsec);delta_sec-=1;delta_nsec+=NSEC_PER_SEC;usbi_err(ctx,"zg: fixed delta_sec %ld delta_nsec %ld",delta_sec,delta_nsec);    }unsigned long longelapsed_us= (unsigned long long)delta_sec*USEC_PER_SEC+                                    (unsigned long long)delta_nsec /1000ULL;...

fully code：

staticintdarwin_reenumerate_device (structlibusb_device_handle*dev_handle,boolcapture) {structdarwin_cached_device*dpriv=DARWIN_CACHED_DEVICE(dev_handle->dev);unsigned longclaimed_interfaces=dev_handle->claimed_interfaces;uint8_tactive_config=dpriv->active_config;UInt32options=0;IOUSBDeviceDescriptordescriptor;IOUSBConfigurationDescriptorPtrcached_configuration;IOUSBConfigurationDescriptor*cached_configurations;IOReturnkresult;UInt8i;structlibusb_context*ctx=HANDLE_CTX (dev_handle);if (dpriv->in_reenumerate) {/* ack, two (or more) threads are trying to reset the device! abort! */returnLIBUSB_ERROR_NOT_FOUND;  }dpriv->in_reenumerate= true;/* store copies of descriptors so they can be compared after the reset */memcpy (&descriptor,&dpriv->dev_descriptor,sizeof (descriptor));cached_configurations=alloca (sizeof (*cached_configurations)*descriptor.bNumConfigurations);for (i=0 ;i<descriptor.bNumConfigurations ;++i) {    (*dpriv->device)->GetConfigurationDescriptorPtr (dpriv->device,i,&cached_configuration);memcpy (cached_configurations+i,cached_configuration,sizeof (cached_configurations[i]));  }/* if we need to release capture */if (get_running_version() >=101000) {if (capture) {#ifMAC_OS_X_VERSION_MAX_ALLOWED >=101000options |=kUSBReEnumerateCaptureDeviceMask;#endif    }  }else {capture= false;  }/* from macOS 10.11 ResetDevice no longer does anything so just use USBDeviceReEnumerate */kresult= (*dpriv->device)->USBDeviceReEnumerate (dpriv->device,options);if (kresult!=kIOReturnSuccess) {usbi_err (ctx,"USBDeviceReEnumerate: %s",darwin_error_str (kresult));dpriv->in_reenumerate= false;returndarwin_to_libusb (kresult);  }/* capture mode does not re-enumerate but it does require re-open */if (capture) {usbi_dbg (ctx,"darwin/reenumerate_device: restoring state...");dpriv->in_reenumerate= false;returndarwin_restore_state (dev_handle,active_config,claimed_interfaces);  }usbi_dbg (ctx,"darwin/reenumerate_device: waiting for re-enumeration to complete...");structtimespecstart;usbi_get_monotonic_time(&start);while (dpriv->in_reenumerate) {structtimespecdelay= {.tv_sec=0, .tv_nsec=1000};nanosleep (&delay,NULL);structtimespecnow;usbi_get_monotonic_time(&now);longdelta_sec=now.tv_sec-start.tv_sec;longdelta_nsec=now.tv_nsec-start.tv_nsec;if (delta_nsec<0) {usbi_err(ctx,"zg: s(%ld %ld) e(%ld %ld)",start.tv_sec,start.tv_nsec,now.tv_sec,now.tv_nsec);usbi_err(ctx,"zg: delta_sec %ld delta_nsec %ld",delta_sec,delta_nsec);delta_sec-=1;delta_nsec+=NSEC_PER_SEC;usbi_err(ctx,"zg: fixed delta_sec %ld delta_nsec %ld",delta_sec,delta_nsec);    }unsigned long longelapsed_us= (unsigned long long)delta_sec*USEC_PER_SEC+                                    (unsigned long long)delta_nsec /1000ULL;if (elapsed_us >=DARWIN_REENUMERATE_TIMEOUT_US) {usbi_err (ctx,"darwin/reenumerate_device: timeout waiting for reenumerate");dpriv->in_reenumerate= false;returnLIBUSB_ERROR_TIMEOUT;    }  }/* compare descriptors */usbi_dbg (ctx,"darwin/reenumerate_device: checking whether descriptors changed");if (memcmp (&descriptor,&dpriv->dev_descriptor,sizeof (descriptor))!=0) {/* device descriptor changed. need to return not found. */usbi_dbg (ctx,"darwin/reenumerate_device: device descriptor changed");returnLIBUSB_ERROR_NOT_FOUND;  }for (i=0 ;i<descriptor.bNumConfigurations ;++i) {    (void) (*dpriv->device)->GetConfigurationDescriptorPtr (dpriv->device,i,&cached_configuration);if (memcmp (cached_configuration,cached_configurations+i,sizeof (cached_configurations[i]))!=0) {usbi_dbg (ctx,"darwin/reenumerate_device: configuration descriptor %d changed",i);returnLIBUSB_ERROR_NOT_FOUND;    }  }usbi_dbg (ctx,"darwin/reenumerate_device: device reset complete. restoring state...");returndarwin_restore_state (dev_handle,active_config,claimed_interfaces);}

[ 0.360327] [00571c28] libusb: error [darwin_reenumerate_device] zg: s(370548 950204000) e(370549 207573000)
[ 0.360354] [00571c28] libusb: error [darwin_reenumerate_device] zg: delta_sec 1 delta_nsec -742631000
[ 0.360400] [00571c28] libusb: error [darwin_reenumerate_device] zg: fixed delta_sec 0 delta_nsec 257369000

tv_nsec is not monotonically increasing; it is periodic, so the calculated delta_nsec can be negative.

With this implementation, although it avoids the somewhat unsightly logic of the if statement that checks for negative values, there is a potential risk of overflow for the unsigned long long type when calculating start_us or now_us

structtimespecstart;usbi_get_monotonic_time(&start);unsigned long longstart_us= (unsigned long long)start.tv_sec*USEC_PER_SEC+                                                   (unsigned long long)start.tv_nsec /1000ULL;while (dpriv->in_reenumerate) {structtimespecdelay= {.tv_sec=0, .tv_nsec=1000};nanosleep (&delay,NULL);structtimespecnow;usbi_get_monotonic_time(&now);unsigned long longnow_us= (unsigned long long)now.tv_sec*USEC_PER_SEC+                                                     (unsigned long long)now.tv_nsec /1000ULL;unsigned long longelapsed_us=now_us-start_us;if (elapsed_us >=DARWIN_REENUMERATE_TIMEOUT_US) {usbi_err (ctx,"darwin/reenumerate_device: timeout waiting for reenumerate");dpriv->in_reenumerate= false;returnLIBUSB_ERROR_TIMEOUT;    }  }

I found the TIMESPEC_SUB macro in libusbi.h. I'm going to use this macro for implementation instead. I'll verify it after 10 hours and then give feedback on the results at that time.@seanm

Ah, I see what you mean now! Nice catch.

Yes, using TIMESPEC_SUB is a good solution.

We should probably also search the codebase fortv_nsec and look for similar mistakes...

Ah, I see what you mean now! Nice catch.

Yes, using TIMESPEC_SUB is a good solution.

We should probably also search the codebase fortv_nsec and look for similar mistakes...

I did a global search and check, and it seems that the same problem also exists in measure of examples/sam3u_benchmark.c.

Do we need to open a new pull request for the merge?

original

staticvoidmeasure(void){structtimevaltv_stop;unsigned longdiff_msec;get_timestamp(&tv_stop);diff_msec= (tv_stop.tv_sec-tv_start.tv_sec)*1000L;diff_msec+= (tv_stop.tv_usec-tv_start.tv_usec) /1000L;printf("%lu transfers (total %lu bytes) in %lu milliseconds => %lu bytes/sec\n",num_xfer,num_bytes,diff_msec, (num_bytes*1000L) /diff_msec);}

fixed

#if !defined(NSEC_PER_SEC)#defineNSEC_PER_SEC1000000000L#endifstaticvoidmeasure(void){structtimevaltv_stop;unsigned longdiff_msec;get_timestamp(&tv_stop);longdiff_sec=tv_stop.tv_sec-tv_start.tv_sec;longdiff_usec=tv_stop.tv_usec-tv_start.tv_usec;if (diff_usec<0) {diff_sec-=1;diff_usec+=NSEC_PER_SEC;}diff_msec= (unsigned long)diff_sec*1000UL;diff_msec+= (unsigned long)diff_usec /1000UL;printf("%lu transfers (total %lu bytes) in %lu milliseconds => %lu bytes/sec\n",num_xfer,num_bytes,diff_msec, (num_bytes*1000L) /diff_msec);}

test

#include<cstdio>structtimeval{longtv_sec;longtv_usec;};voidoriginal(longsec1,longusec1,longsec2,longusec2){unsigned longdiff_msec;structtimevaltv_start,tv_stop;tv_start.tv_sec=sec2;tv_start.tv_usec=usec2;tv_stop.tv_sec=sec1;tv_stop.tv_usec=usec1;diff_msec= (tv_stop.tv_sec-tv_start.tv_sec)*1000L;diff_msec+= (tv_stop.tv_usec-tv_start.tv_usec) /1000L;printf("%s %lu\n",__FUNCTION__,diff_msec);}voidfixed(longsec1,longusec1,longsec2,longusec2){unsigned longdiff_msec;structtimevaltv_start,tv_stop;tv_start.tv_sec=sec2;tv_start.tv_usec=usec2;tv_stop.tv_sec=sec1;tv_stop.tv_usec=usec1;longdiff_sec=tv_stop.tv_sec-tv_start.tv_sec;longdiff_usec=tv_stop.tv_usec-tv_start.tv_usec;if (diff_usec<0) {diff_sec-=1;diff_usec+=1000000000;}diff_msec=diff_sec*1000UL;diff_msec+=diff_usec /1000UL;printf("%s %lu\n",__FUNCTION__,diff_msec);}intmain(void){// positive testsoriginal(1/*end sec*/,2000/*end usec*/,0/*start sec*/,0/*start usec*/);fixed(1,2000,0,0);// nagtive testsoriginal(1,0,0,2000);fixed(1,0,0,2000);return0;}// output of test code as belloworiginal1002fixed1002original998fixed999998

Do we need to open a new pull request for the merge?

You can add to this PR.

Ah, I see what you mean now! Nice catch.
Yes, using TIMESPEC_SUB is a good solution.
We should probably also search the codebase fortv_nsec and look for similar mistakes...

I did a global search and check, and it seems that the same problem also exists in measure of examples/sam3u_benchmark.c.

Do we need to open a new pull request for the merge?

libusb/examples/sam3u_benchmark.c

Line 164 inde38189

diff_msec= (tv_stop.tv_sec-tv_start.tv_sec)*1000L;

original

staticvoidmeasure(void){structtimevaltv_stop;unsigned longdiff_msec;get_timestamp(&tv_stop);diff_msec= (tv_stop.tv_sec-tv_start.tv_sec)*1000L;diff_msec+= (tv_stop.tv_usec-tv_start.tv_usec) /1000L;printf("%lu transfers (total %lu bytes) in %lu milliseconds => %lu bytes/sec\n",num_xfer,num_bytes,diff_msec, (num_bytes*1000L) /diff_msec);}

fixed

#if !defined(NSEC_PER_SEC)#defineNSEC_PER_SEC1000000000L#endifstaticvoidmeasure(void){structtimevaltv_stop;unsigned longdiff_msec;get_timestamp(&tv_stop);longdiff_sec=tv_stop.tv_sec-tv_start.tv_sec;longdiff_usec=tv_stop.tv_usec-tv_start.tv_usec;if (diff_usec<0) {diff_sec-=1;diff_usec+=NSEC_PER_SEC;}diff_msec= (unsigned long)diff_sec*1000UL;diff_msec+= (unsigned long)diff_usec /1000UL;printf("%lu transfers (total %lu bytes) in %lu milliseconds => %lu bytes/sec\n",num_xfer,num_bytes,diff_msec, (num_bytes*1000L) /diff_msec);}

test

#include<cstdio>structtimeval{longtv_sec;longtv_usec;};voidoriginal(longsec1,longusec1,longsec2,longusec2){unsigned longdiff_msec;structtimevaltv_start,tv_stop;tv_start.tv_sec=sec2;tv_start.tv_usec=usec2;tv_stop.tv_sec=sec1;tv_stop.tv_usec=usec1;diff_msec= (tv_stop.tv_sec-tv_start.tv_sec)*1000L;diff_msec+= (tv_stop.tv_usec-tv_start.tv_usec) /1000L;printf("%s %lu\n",__FUNCTION__,diff_msec);}voidfixed(longsec1,longusec1,longsec2,longusec2){unsigned longdiff_msec;structtimevaltv_start,tv_stop;tv_start.tv_sec=sec2;tv_start.tv_usec=usec2;tv_stop.tv_sec=sec1;tv_stop.tv_usec=usec1;longdiff_sec=tv_stop.tv_sec-tv_start.tv_sec;longdiff_usec=tv_stop.tv_usec-tv_start.tv_usec;if (diff_usec<0) {diff_sec-=1;diff_usec+=1000000000;}diff_msec=diff_sec*1000UL;diff_msec+=diff_usec /1000UL;printf("%s %lu\n",__FUNCTION__,diff_msec);}intmain(void){// positive testsoriginal(1/*end sec*/,2000/*end usec*/,0/*start sec*/,0/*start usec*/);fixed(1,2000,0,0);// nagtive testsoriginal(1,0,0,2000);fixed(1,0,0,2000);return0;}// output of test code as belloworiginal1002fixed1002original998fixed999998

@seanm The Darwin code has been successfully tested on my macOS terminal. As for the sam3u_benchmark code, since I do not have the device (16c0:0763), I have only verified its correctness using the previous test code. What else do I need to do for this pull request?

What else do I need to do for this pull request?

You could try to get other reviewers I suppose... maybe by looking at other active users here on github...

But otherwise you have to wait for someone with merge access to voice an opinion...

@mcuee I need some help with reviewing the this PR. Thand you.
This PR is not related to the platform.

@mcuee I need some help with reviewing the this PR. Thand you. This PR is not related to the platform.

Unfortunately I am not able to review this properly myself (more in the role of testing and supporting as I do not know much about programming myself. Basically I cannot code and I can only review simple codes). Need the review from either@tormodvolden or@hjelmn.

I can take a look. I am trying to find more time to actively work on libusb. Should have time tomorrow to look at all open PRs.

I can take a look. I am trying to find more time to actively work on libusb. Should have time tomorrow to look at all open PRs.

That's great@hjelmn ! I don't know if you already saw it, we are planning a release with what is in master now, before merging anything new. I'll roll a RC maybe today.

@hjelmn

Ping. Thanks.

@hjelmn

Fixes#1637. A part from the version_nano.h change, this looks good.

@HotIce0 Is your full name correctly written "Zeng Guang"?

@HotIce0 Is your full name correctly written "Zeng Guang"?
yes

Fixes#1637. A part from the version_nano.h change, this looks good.

I directly deleted the updated part of the version_nano.h file. it's too prone to conflicts since it keeps changing all the time.

Thanks, yes that file shouldn't be changed in pull requests.

I have merged the Darwin regression fix.@HotIce0 Thanks for your contribution!

However, I think the sam3u_benchmark change doesn't fix anything. The original code was correct. It looks like microseconds and nanoseconds got mixed up in the test case. (The test case is a great idea though!) If you fix up thediff_usec += 1000000000; typo the test case will succeed. Your change only affects sub-millisecond deltas, and changes from rounding down to rounding up.

Ideally it should just useTIMESPEC_SUB and not reinvent the wheel.

[ 0.360327] [00571c28] libusb: error [darwin_reenumerate_device] zg: s(370548 950204000) e(370549 207573000) [ 0.360354] [00571c28] libusb: error [darwin_reenumerate_device] zg: delta_sec 1 delta_nsec -742631000 [ 0.360400] [00571c28] libusb: error [darwin_reenumerate_device] zg: fixed delta_sec 0 delta_nsec 257369000

Unfortunately I cannot reproduce such issues using xusb and disks. No error on my side.

But interestingly I can see different results of git head and libusb 1.0.28 release.

• libusb_attach_kernel_driver on MacOS segfaults #1635 (comment)

Not so sure if it is due to commit9cef804 which fixed#1637 and also mentioned here.

Reference:

• [macOS] Changes to remove compiler warnings breaks macOS re-enumeration timeout. #1637

From here:#1635 (comment), comment by Tormod Volden.

That's great. However, that commit only prevents timeout. It is possible that the absence of timeout now avoids the issue causing the segfault in this report. But if libusb still may segfault when there is a timeout or other device timing issue, there must be a vulnerability that we should try to fix IMO. libusb should never segfault, whatever timing and device behavior is taking place.

I can take a look. I am trying to find more time to actively work on libusb. Should have time tomorrow to look at all open PRs.

@hjelmn If you find some spare cycles, I would particularly appreciate if you give your opinion on suggested API changes ( APIAPI changes) where you haven't already. You don't necessarily need to look at the implementations, just the API itself, if it makes sense and seems the best way forward. Most times we have people reviewing the code but the really hard question is how do we want our API to evolve. You have been developing and shaping the libusb API for many years and I hope you will continue to be involved for long.

This was fixed in 1.0.29.

The second commit hasn't been merged.

The second commit hasn't been merged.

Because you said you didn't like the change.

Yes, the first commit was an important regression fix, so it was merged for 1.0.29. The second commit doesn't seem to solve any problem. And it was only tested with a test case that had errors. I'd expect the submitter to fix the test case. But the code change can still be considered, if it e.g. makes the code easier to read or maintain.

It is pretty much the equivalent of TIMESPEC_SUB but for milliseconds instead of nanoseconds.