Thread Performance Checker: Thread running at User-interactive quality-of-service class waiting on a lower QoS thread running at Default quality-of-service class.

[nastasiupta]

Full debug logs:

Thread Performance Checker: Thread running at User-interactive quality-of-service class waiting on a lower QoS thread running at Default quality-of-service class. Investigate ways to avoid priority inversions
PID: 70339, TID: 4422014
Backtrace
=================================================================
3   AppNameHere                           0x0000000105bff3dc $s8NIOPosix13NIOThreadPoolC6_start16threadNamePrefixySS_tF + 1524
4   AppNameHere                           0x0000000105c0004c $s8NIOPosix13NIOThreadPoolC5startyyF + 60
5   AppNameHere                           0x00000001055a481c $s6SotoS30B0V18ThreadPoolProviderO6create8NIOPosix09NIOThreadD0CyF + 124
6   AppNameHere                           0x00000001055aab24 $s6SotoS30B0V26openFileForMultipartUpload8filename6logger2on18threadPoolProvider14uploadCallback7NIOCore15EventLoopFutureCyAC08CompletefG6OutputVGSS_7Logging6LoggerVAJ0qR0_pAC06ThreadlM0OAoJ13NIOFileHandleC_AJ0D6RegionV8NIOPosix011NonBlockingD2IOVtctF + 156
7   AppNameHere                           0x00000001055aa888 $s6SotoS30B0V15multipartUpload_8partSize8filename11abortOnFail6logger2on18threadPoolProvider8progress7NIOCore15EventLoopFutureCyAC017CompleteMultipartD6OutputVGAC06CreatevD7RequestV_SiSSSb7Logging6LoggerVAL0rS0_pSgAC06ThreadnO0OySdKctF + 1244
8   AppNameHere                           0x00000001050ffa5c $s9AppNameHere19AWSFileUploadWorkerC7execute4data10completionyAC7RequestV_ySSSg_AC8ResponseVSgtcSgtF + 4424
9   AppNameHere                           0x0000000104f64514 $s9AppNameHere16FileUploadWorkerC7execute4data10completionyAC7RequestC_ySSSg_AC8ResponseVSgtcSgtF05startcD0L_yyF + 536
10  AppNameHere                           0x0000000104f642a4 $s9AppNameHere16FileUploadWorkerC7execute4data10completionyAC7RequestC_ySSSg_AC8ResponseVSgtcSgtF + 984
11  AppNameHere                           0x0000000105218108 $s9AppNameHere13LFFileManagerC18uploadPendingFiles33_A43F4D69DB085DD12FA6694232CB9D21LLyyF6handleL_0E7RequestyAA16FileUploadWorkerC0Q0C_tF + 348
12  AppNameHere                           0x0000000105217f80 $s9AppNameHere13LFFileManagerC18uploadPendingFiles33_A43F4D69DB085DD12FA6694232CB9D21LLyyF + 344
13  AppNameHere                           0x0000000105219174 $s9AppNameHere13LFFileManagerC18uploadPendingFiles33_A43F4D69DB085DD12FA6694232CB9D21LLyyF6handleL_0E7RequestyAA16FileUploadWorkerC0Q0C_tFySSSg_AI8ResponseVSgtcfU_ + 4160
14  AppNameHere                           0x0000000104f65158 $s9AppNameHere16FileUploadWorkerC7execute4data10completionyAC7RequestC_ySSSg_AC8ResponseVSgtcSgtF05startcD0L_yyFyAI_AA07AWSFiledE0CAJVSgtcfU_yAI_AA08FSUploadE0CAJVSgtcfU_ + 1032
15  AppNameHere                           0x0000000104f504b8 $s9AppNameHere14FSUploadWorkerC7execute4data10completionyAC7RequestV_ySSSg_AC8ResponseVSgtcSgtFyAI_AA10RESTWorkerCAJVSgtcfU_ + 1268
16  AppNameHere                           0x000000010525a1c8 $s9AppNameHere10RESTWorkerC7execute4data10completionyAC7RequestV_ySSSg_AC8ResponseVSgtcSgtFy9Alamofire04DataH0Vy10Foundation0J0VAN7AFErrorOGcfU0_ + 3168
17  AppNameHere                           0x00000001063c6a2c $s9Alamofire11DataRequestC9_response33_39EEDF845955893097265C4B130CD574LL5queue0D10Serializer17completionHandlerACXDSo012OS_dispatch_I0C_xyAA0B8ResponseVy16SerializedObjectQzAA7AFErrorOGctAA0boJ8ProtocolRzlFyycfU_yyYbcfU1_yycfU_yyYbcfU_ + 124
18  AppNameHere                           0x00000001063045ac $sIegh_IeyBh_TR + 48
19  libdispatch.dylib                   0x0000000108aa0f14 _dispatch_call_block_and_release + 32
20  libdispatch.dylib                   0x0000000108aa2b4c _dispatch_client_callout + 20
21  libdispatch.dylib                   0x0000000108ab5dcc _dispatch_main_queue_drain + 1100
22  libdispatch.dylib                   0x0000000108ab5970 _dispatch_main_queue_callback_4CF + 44
23  CoreFoundation                      0x000000018a95d220 __CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__ + 16
24  CoreFoundation                      0x000000018a91aaac __CFRunLoopRun + 1996
25  CoreFoundation                      0x000000018a919c2c CFRunLoopRunSpecific + 608
26  HIToolbox                           0x0000000194e72448 RunCurrentEventLoopInMode + 292
27  HIToolbox                           0x0000000194e72284 ReceiveNextEventCommon + 648
28  HIToolbox                           0x0000000194e71fdc _BlockUntilNextEventMatchingListInModeWithFilter + 76
29  AppKit                              0x000000018e0f4f90 _DPSNextEvent + 660
30  AppKit                              0x000000018e8c8b94 -[NSApplication(NSEventRouting) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 716
31  AppKit                              0x000000018e0e843c -[NSApplication run] + 476
32  AppKit                              0x000000018e0bf708 NSApplicationMain + 880
33  AppNameHere                           0x000000010530eea8 $sSo21NSApplicationDelegateP6AppKitE4mainyyFZ + 40
34  AppNameHere                           0x000000010530ee70 $s9AppNameHere11AppDelegateC5$mainyyFZ + 44
35  AppNameHere                           0x000000010530f070 main + 28
36  dyld                                0x000000018a4c5058 start + 2224

I'm using S3 to upload multipart content and sometimes happens to receive those logs and progress/completion closures are not called, resulting that the file is stuck on "uploading" state.

Setup (please complete the following information):

• OS: macOS Sonoma 14.0
• Version of soto: 6.7
• Authentication mechanism [hard-coded credentials, IAM Instance Profile on EC2, etc]

let cpf = CredentialProviderFactory.static(accessKeyId: adtConfiguration.pk,
                                           secretAccessKey: adtConfiguration.sk)
let awsClient = AWSClient(credentialProvider: cpf, httpClientProvider: .createNew)
let region = SotoS3.Region(awsRegionName: adtConfiguration.region)
var s3 = S3(client: awsClient, region: region, timeout: .minutes(2))
if adtConfiguration.useAccelerateEndpoint {
    s3 = s3.with(options: .s3UseTransferAcceleratedEndpoint)
}
self.s3 = s3
let request = S3.CreateMultipartUploadRequest(bucket: adtConfiguration.bucket,
                                              contentType: fileURL.mimeType,
                                              key: data.file.serverFileName(withUserUID: true))

s3.multipartUpload(request,
                   partSize: InformationKeeper.shared.otherFileChunkSize,
                   filename: fileURL.path) { progress in
    if self.isCancelled == false {
        handle(progress: progress)
    }
}
                   .whenComplete { (uploadResult) in
                       handle(uploadResult: uploadResult)
                   }

[adam-fowler]

What QoS is calling code running at?

[nastasiupta]

On the main...

[adam-fowler]

Ok one possibility is a thread pool is being created every time you call that function and this is causing issues. Instead you could create a global NIOThreadPool and pass it to s3. multipartUpload as threadPoolProvider: .shared(myThreadPool).

Recently swift-nio supplied a singleton version of the NIOThreadPool. I can change the default to use this singleton instead of creating a new one every time the function is called

[adam-fowler]

PR for using singleton instead #695

[nastasiupta]

@adam-fowler new version release ?

[adam-fowler]

The PR needs approved first

[nastasiupta]

@adam-fowler can you solve today?

[adam-fowler]

While waiting for a new release you should be able to use threadPoolProvider: .shared(NIOThreadPool.singleton) in your multipartUpload call to resolve your issue.

[nastasiupta]

Hmm, I tried but is not solving the issue:

Thread Performance Checker: Thread running at User-interactive quality-of-service class waiting on a lower QoS thread running at Default quality-of-service class. Investigate ways to avoid priority inversions
PID: 39945, TID: 5500604
Backtrace
=================================================================
3   AppNameHere                           0x0000000104d6f540 $s8NIOPosix13NIOThreadPoolC6_start16threadNamePrefixySS_tF + 1524
4   AppNameHere                           0x0000000104d6eed4 $s8NIOPosix13NIOThreadPoolC021_makePerpetualStartedC015numberOfThreads16threadNamePrefixACSi_SStFZ + 104
5   AppNameHere                           0x0000000104da30cc $s8NIOPosix23globalPosixBlockingPool33_54795181D6A4669A6950FD635B385752LLAA09NIOThreadE0CvpfiAEyXEfU_ + 132
6   AppNameHere                           0x0000000104da3038 $s8NIOPosix23globalPosixBlockingPool33_54795181D6A4669A6950FD635B385752LL_WZ + 12
7   libdispatch.dylib                   0x0000000107c02b4c _dispatch_client_callout + 20
8   libdispatch.dylib                   0x0000000107c04a64 _dispatch_once_callout + 160
9   AppNameHere                           0x0000000104da2e68 $s8NIOPosix23globalPosixBlockingPool33_54795181D6A4669A6950FD635B385752LLAA09NIOThreadE0Cvau + 80
10  AppNameHere                           0x0000000104da2dfc $s7NIOCore13NIOSingletonsO8NIOPosixE23posixBlockingThreadPoolAD09NIOThreadG0CvgZ + 16
11  AppNameHere                           0x0000000104da2ed0 $s8NIOPosix13NIOThreadPoolC9singletonACvgZ + 24
12  AppNameHere                           0x000000010426f354 $s9AppNameHere19AWSFileUploadWorkerC7execute4data10completionyAC7RequestV_ySSSg_AC8ResponseVSgtcSgtF + 4140
13  AppNameHere                           0x00000001040d678c $s9AppNameHere16FileUploadWorkerC7execute4data10completionyAC7RequestC_ySSSg_AC8ResponseVSgtcSgtF05startcD0L_yyF + 536
14  AppNameHere                           0x00000001040d651c $s9AppNameHere16FileUploadWorkerC7execute4data10completionyAC7RequestC_ySSSg_AC8ResponseVSgtcSgtF + 984
15  AppNameHere                           0x0000000104388a98 $s9AppNameHere13LFFileManagerC18uploadPendingFiles33_A43F4D69DB085DD12FA6694232CB9D21LLyyF6handleL_0E7RequestyAA16FileUploadWorkerC0Q0C_tF + 348
16  AppNameHere                           0x0000000104388910 $s9AppNameHere13LFFileManagerC18uploadPendingFiles33_A43F4D69DB085DD12FA6694232CB9D21LLyyF + 344
17  AppNameHere                           0x00000001043805f4 $s9AppNameHere13LFFileManagerC11uploadFiles4urlsySay10Foundation3URLVG_tF + 1152
18  AppNameHere                           0x0000000104312d00 $s9AppNameHere21FileManagerHeaderViewV4bodyQrvg7SwiftUI05TupleF0VyAE0F0PAEE7paddingyQrAE4EdgeO3SetV_12CoreGraphics7CGFloatVSgtFQOyAiEE5frame5width6height9alignmentQrAR_ArE9AlignmentVtFQOyAE6HStackVyAGyAE06ScrollF0VyAZyAGyAC09componentF033_FF7633ACFDEA3379B9E4F13A23535CF6LL4text10isSelected12onTapGestureQrAA10BaseStringO_SbyyctFQOy_Qo__AE7ForEachVySayAA6FolderVGSSA8_GtGGGSg_AE6SpacerVAGyAA11ImageButtonVSg_A23_A22_tGSgAiEEAstuVQrAR_ArXtFQOyA20__Qo_A22_A22_A26_AE6VStackVyAiEE12cornerRadius_11antialiasedQrAQ_SbtFQOyAZyAGyAiEE11buttonStyleyQrqd__AE20PrimitiveButtonStyleRd__lFQOyAE6ButtonVyAiEE10background_AVQrqd___AXtAeHRd__lFQOyAiEEAstuVQrAR_ArXtFQOyAiEE15foregroundColoryQrAE5ColorVSgFQOyAE5ImageV_Qo__Qo__A38_Qo_G_AE16PlainButtonStyleVQo__A48_tGG_Qo_GtGG_Qo__Qo__AiEEAJyQrAN_ARtFQOyAiEEAstuVQrAR_ArXtFQOyAZyAGyAiEEA31_yQrqd__AEA32_Rd__lFQOyA34_yA41_G_A47_Qo_Sg_AE19_ConditionalContentVyAE4TextVA63_GA20_AZyAGyAA15SearchTextFieldV_AiEE9fixedSizeQryFQOyAiEE9menuStyleyQrqd__AE9MenuStyleRd__lFQOyAE4MenuVyAiEEA29__A30_QrAQ_SbtFQOyAiEEA35__AVQrqd___AXtAeHRd__lFQOyAiEEAstuVQrAR_ArXtFQOyA28_yA61_yA41_A41_GG_Qo__A38_Qo__Qo_AGyA28_yAGyA63__A34_yAGyA72__A63_tGGA78_A78_A78_A78_AA09SeparatorF0VtGG_A82_A28_yAGyA63__A78_A78_tGGtGG_AE25BorderlessButtonMenuStyleVQo__Qo_AA15SecondaryButtonVA92_tGGtGG_Qo__Qo_tGyXEfU_A95_yXEfU0_A93_yXEfU0_yycfU3_ySayAA012ErrorOverlayF0V6ActionVGSg_Say10Foundation3URLVGSgtcfU_ + 1688
19  AppNameHere                           0x000000010420e928 $s9AppNameHere17FilesPickerWorkerC7execute4data10completionyAA0cD13ConfigurationV_ySayAA16ErrorOverlayViewV6ActionVGSg_Say10Foundation3URLVGSgtcSgtF + 2376
20  AppNameHere                           0x000000010431263c $s9AppNameHere21FileManagerHeaderViewV4bodyQrvg7SwiftUI05TupleF0VyAE0F0PAEE7paddingyQrAE4EdgeO3SetV_12CoreGraphics7CGFloatVSgtFQOyAiEE5frame5width6height9alignmentQrAR_ArE9AlignmentVtFQOyAE6HStackVyAGyAE06ScrollF0VyAZyAGyAC09componentF033_FF7633ACFDEA3379B9E4F13A23535CF6LL4text10isSelected12onTapGestureQrAA10BaseStringO_SbyyctFQOy_Qo__AE7ForEachVySayAA6FolderVGSSA8_GtGGGSg_AE6SpacerVAGyAA11ImageButtonVSg_A23_A22_tGSgAiEEAstuVQrAR_ArXtFQOyA20__Qo_A22_A22_A26_AE6VStackVyAiEE12cornerRadius_11antialiasedQrAQ_SbtFQOyAZyAGyAiEE11buttonStyleyQrqd__AE20PrimitiveButtonStyleRd__lFQOyAE6ButtonVyAiEE10background_AVQrqd___AXtAeHRd__lFQOyAiEEAstuVQrAR_ArXtFQOyAiEE15foregroundColoryQrAE5ColorVSgFQOyAE5ImageV_Qo__Qo__A38_Qo_G_AE16PlainButtonStyleVQo__A48_tGG_Qo_GtGG_Qo__Qo__AiEEAJyQrAN_ARtFQOyAiEEAstuVQrAR_ArXtFQOyAZyAGyAiEEA31_yQrqd__AEA32_Rd__lFQOyA34_yA41_G_A47_Qo_Sg_AE19_ConditionalContentVyAE4TextVA63_GA20_AZyAGyAA15SearchTextFieldV_AiEE9fixedSizeQryFQOyAiEE9menuStyleyQrqd__AE9MenuStyleRd__lFQOyAE4MenuVyAiEEA29__A30_QrAQ_SbtFQOyAiEEA35__AVQrqd___AXtAeHRd__lFQOyAiEEAstuVQrAR_ArXtFQOyA28_yA61_yA41_A41_GG_Qo__A38_Qo__Qo_AGyA28_yAGyA63__A34_yAGyA72__A63_tGGA78_A78_A78_A78_AA09SeparatorF0VtGG_A82_A28_yAGyA63__A78_A78_tGGtGG_AE25BorderlessButtonMenuStyleVQo__Qo_AA15SecondaryButtonVA92_tGGtGG_Qo__Qo_tGyXEfU_A95_yXEfU0_A93_yXEfU0_yycfU3_ + 372
21  SwiftUI                             0x00000001b6842188 OUTLINED_FUNCTION_2 + 900
22  SwiftUI                             0x00000001b5ed8838 __swift_memcpy3_1 + 10188
23  SwiftUI                             0x00000001b5edc760 __swift_memcpy3_1 + 26356
24  SwiftUI                             0x00000001b5edc6ac __swift_memcpy3_1 + 26176
25  SwiftUI                             0x00000001b64c52e8 OUTLINED_FUNCTION_0 + 5048
26  SwiftUI                             0x00000001b530d558 OUTLINED_FUNCTION_37 + 1502636
27  SwiftUI                             0x00000001b5fe5bd0 OUTLINED_FUNCTION_8 + 760
28  SwiftUI                             0x00000001b606c0d0 OUTLINED_FUNCTION_2 + 40
29  SwiftUI                             0x00000001b5fe5bd0 OUTLINED_FUNCTION_8 + 760
30  SwiftUI                             0x00000001b682fd84 OUTLINED_FUNCTION_4 + 4424
31  SwiftUI                             0x00000001b682f53c OUTLINED_FUNCTION_4 + 2304
32  SwiftUI                             0x00000001b69dd1e4 OUTLINED_FUNCTION_3 + 1732
33  SwiftUI                             0x00000001b5deadd0 OUTLINED_FUNCTION_16 + 32804
34  SwiftUI                             0x00000001b5deb428 OUTLINED_FUNCTION_16 + 34428
35  SwiftUI                             0x00000001b5df47c0 OUTLINED_FUNCTION_16 + 72212
36  SwiftUI                             0x00000001b5df45dc OUTLINED_FUNCTION_16 + 71728
37  AppKit                              0x000000018ec0de24 _routeMouseUpEvent + 132
38  AppKit                              0x000000018e220b80 -[NSWindow(NSEventRouting) _reallySendEvent:isDelayedEvent:] + 384
39  AppKit                              0x000000018e22082c -[NSWindow(NSEventRouting) sendEvent:] + 284
40  AppKit                              0x000000018e8c7c08 -[NSApplication(NSEventRouting) sendEvent:] + 1556
41  AppKit                              0x000000018e51b1bc -[NSApplication _handleEvent:] + 60
42  AppKit                              0x000000018e0e8460 -[NSApplication run] + 512
43  AppKit                              0x000000018e0bf708 NSApplicationMain + 880
44  AppNameHere                           0x000000010447ea34 $sSo21NSApplicationDelegateP6AppKitE4mainyyFZ + 40
45  AppNameHere                           0x000000010447e9fc $s9AppNameHere11AppDelegateC5$mainyyFZ + 44
46  AppNameHere                           0x000000010447ebfc main + 28
47  dyld                                0x000000018a4c5058 start + 2224

[adam-fowler]

Ok, It looks like a similar issue apple/swift-nio#2223 I've seen on the swift-nio repository. The suggested way to resolve this was initialise the singleton on a background thread. This is going to require a little more work to get rid of the warning.

Does the upload still fail after seeing the warning above?

[nastasiupta]

Yes... I mean is not failing (calling the completion function with an error), it's just stuck...

[adam-fowler]

As a test can you stick the following lines somewhere in the initialisation for your application

DispatchQueue.global(qos: .background).async {
    _ = NIOThreadPool.singleton
}

[nastasiupta]

@adam-fowler tested... in the debugger there is no warning displayed, but the upload process is stuck..

[adam-fowler]

@adam-fowler tested... in the debugger there is no warning displayed, but the upload process is stuck..

Ok looks like we have two issues here. The warning about thread priorities and then the hang.

For the hang can we clean the code up a little. And also add some logging to get a better idea what is going on

1. The AWSClient should be global. You shouldn't create one for each upload operation.
2. With the current setup you must be calling AWSClient.syncShutdown somewhere otherwise you would get an error when the client is deleted. Where is this being called? If it is immediately after the multipartUpload call then that'll be the probable cause of your issues. multipartUpload starts an asynchronous process. That process is not complete when it returns. So calling syncShutdown immediately after will kill the process before it completes.
3. Lets pass a Logger to the multipartUpload operation to see if we get any output.

var logger = Logger(label: "s3hang")
logger.logLevel = .trace
// Your s3 multipart upload call
s3.multipartUpload(request, ..., logger: logger)

4. We can also get Soto to output details about every request sent to AWS

s3 = s3.with(middlewares: AWSLoggingMiddleware()

[nastasiupta]

@adam-fowler I sent you an email with the logs file. Also, regarding the first point "The AWSClient should be global. You shouldn't create one for each upload operation." I might have an issue. The app supports multiple accounts and it can happen to have a different configuration for each account. Even if I optimise for use a single instance for an user, if there 10 accounts connected on the same app, I want to use different instances because each user has his own configuration.

[adam-fowler]

Are you uploading all of these at the same time? You might want to queue them. You could be opening too many connections.

[nastasiupta]

Maximum 5 uploads. So the user can select 100 files, but I take care to have 5 uploads at the same time, when one is ended, then I start another one. Do you think 5 uploads at a time maybe be to much?

It worked perfect for a long period of time... things are broken recenly

[adam-fowler]

Just looking through the logs you sent.

• From the log I only see 18 files being loaded. It appears the other 2 don't get loaded at all. Are you sure you are calling the multipart upload 20 times?
• Of those 18 uploads only one is larger than 5MB and might benefit from multipartUpload over putObject.

[nastasiupta]

Yes, all the files goes to multipart upload. In previous versions we had made some "hard core tests" like uploading more than 100+ files... selecting like 5 big videos and images, after the batch is ready, start again with other images and so on. Something happen in the last Soto SDK updates... We released the app in 2021 and we didn't had any use in the previous releases.
We use multipart because in 99% of the cases our users are having images bigger than 5mb :).

[adam-fowler]

I only see 18 Open file ... log entries. This is output as soon as the multipart upload function has opened a file ie the first operation it performs. Can you please verify the number of times you are calling the function by adding a log entry prior to calling multipartUpload.

[nastasiupta]

Check email, I sent you some screenshots as well and a new logs file, this time stopped sooner...

[adam-fowler]

Are you able to use a branch of Soto. If so could you use the threadpool-singleton branch. And send me the logs from that.

[adam-fowler]

Also if you aren't able to use one AWSClient could you at least use just the one HTTPClient instead of creating a new one with each AWSClient.

import AsyncHTTPClient

let globalHTTPClient = HTTPClient(eventLoopGroupProvider: .singleton)

let awsClient = AWSClient(..., httpClientProvider: .shared(globalHTTPClient))

[nastasiupta]

Tried both, using singleton for HTTPClient cause a crash, I sent you an email with more details & logs

[adam-fowler]

Sorry I wasn't clear enough globalHTTPClient has to be a global variable. The idea is there is one HTTP client used by all of the AWSClients.

[nastasiupta]

I did as you said, tried 3 tests with 20 images each time, works like a charm.

[adam-fowler]

I think the issue you were seeing was related to the fact each HTTPClient you create, creates a new EventLoopGroup and a new connection pool. Your application was creating an HTTPClient for every request which could cause a thread explosion.

[nastasiupta]

Oh wow, hmmm, should I wait for the SDK update before doing a new release? Maybe a mechanism, by default, to prevent things like this to happen?

[adam-fowler]

6.8 has been released with the singleton stuff