Skip to content

Commit d0f5acb

Browse files
FrizlabFrizlab
committed
Dummy log enhancements
1 parent e05d60e commit d0f5acb

File tree

2 files changed

+52
-36
lines changed

2 files changed

+52
-36
lines changed

‎Sources/SignalHandling/DelayedSigaction/SigactionDelayer_Block.swift‎

Lines changed: 26 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -120,7 +120,12 @@ public enum SigactionDelayer_Block {
120120
} catch {
121121
for (signal, UnsigactionID) in ret {
122122
do {try unregisterDelayedSigactionOnQueue(UnsigactionID)}
123-
catch {SignalHandlingConfig.logger?.error("Cannot unregister delayed sigaction for in recovery handler of registerDelayedSigactions. The signal will stay blocked, probably forever.", metadata: ["signal": "\(signal)"])}
123+
catch {
124+
SignalHandlingConfig.logger?.error(
125+
"Cannot unregister delayed sigaction for in recovery handler of registerDelayedSigactions. The signal will stay blocked, probably forever.",
126+
metadata: ["signal": "\(signal)", "error": "\(error)"]
127+
)
128+
}
124129
}
125130
throw error
126131
}
@@ -252,7 +257,10 @@ public enum SigactionDelayer_Block {
252257
signalProcessingQueue.async{
253258
do {try currentSigaction.install(on: signal)}
254259
catch {
255-
SignalHandlingConfig.logger?.error("Cannot set original sigaction back for signal \(signal) after signal source activation. You might never be called in the sigaction handler and get an infinite loop of signal calls once this signal has been sent once.")
260+
SignalHandlingConfig.logger?.error(
261+
"Cannot set original sigaction back for signal after signal source activation. You might never be called in the sigaction handler and get an infinite loop of signal calls once this signal has been sent once.",
262+
metadata: ["signal": "\(signal)", "error": "\(error)"]
263+
)
256264
}
257265
}
258266
#endif
@@ -273,15 +281,15 @@ public enum SigactionDelayer_Block {
273281
guard var blockedSignal = blockedSignals[signal] else {
274282
/* We trust our source not to have an internal logic error.
275283
* If the delayed sigaction is not found, it is because the callee called unregister twice on the same delayed sigaction. */
276-
SignalHandlingConfig.logger?.error("Delayed sigaction unregistered more than once", metadata: ["signal": "\(signal)"])
284+
SignalHandlingConfig.logger?.error("Delayed sigaction unregistered more than once.", metadata: ["signal": "\(signal)"])
277285
return
278286
}
279287
assert(!blockedSignal.handlers.isEmpty, "INTERNAL ERROR: handlers should never be empty because when it is, the whole delayed signal should be removed.")
280288

281289
guard blockedSignal.handlers.removeValue(forKey: delayedSigaction) != nil else {
282290
/* Same here.
283291
* If the delayed sigaction was not in the handlers, it can only be because the callee called unregister twice with the object. */
284-
SignalHandlingConfig.logger?.error("Delayed sigaction unregistered more than once", metadata: ["signal": "\(signal)"])
292+
SignalHandlingConfig.logger?.error("Delayed sigaction unregistered more than once.", metadata: ["signal": "\(signal)"])
285293
return
286294
}
287295

@@ -304,7 +312,7 @@ public enum SigactionDelayer_Block {
304312

305313
/** Must always be called on the `signalProcessingQueue`. */
306314
private static func processSignalsOnQueue(signal: Signal, count: UInt) {
307-
SignalHandlingConfig.logger?.debug("Processing signals, called from libdispatch", metadata: ["signal": "\(signal)", "count": "\(count)"])
315+
SignalHandlingConfig.logger?.debug("Processing signals, called from libdispatch.", metadata: ["signal": "\(signal)", "count": "\(count)"])
308316

309317
/* Get the delayed signal for the given signal. */
310318
guard let blockedSignal = blockedSignals[signal] else {
@@ -327,14 +335,17 @@ public enum SigactionDelayer_Block {
327335
/* All the handlers have responded, we now know whether to allow or drop the signal. */
328336
do {try executeOnThread(runOriginalHandlerFinal ? .suspend(for: signal) : .drop(signal))}
329337
catch {
330-
SignalHandlingConfig.logger?.error("Error while \(runOriginalHandlerFinal ? "suspending thread" : "dropping signal in thread").", metadata: ["signal": "\(signal)"])
338+
SignalHandlingConfig.logger?.error(
339+
"Error while \(runOriginalHandlerFinal ? "suspending thread" : "dropping signal in thread").",
340+
metadata: ["signal": "\(signal)", "error": "\(error)"]
341+
)
331342
}
332343
}
333344
}
334345

335346
private static func blockedSignalsThreadLoop() {
336347
runLoop: repeat {
337-
// loggerLessThreadSafeDebugLog("🧵 New blocked signals thread loop")
348+
// loggerLessThreadSafeDebugLog("🧵 New blocked signals thread loop…")
338349

339350
#if !os(Linux)
340351
ThreadSync.lock.lock(whenCondition: ThreadSync.actionInThread.rawValue)
@@ -354,31 +365,31 @@ public enum SigactionDelayer_Block {
354365
switch ThreadSync.action {
355366
case .nop:
356367
(/*nop*/)
357-
// loggerLessThreadSafeDebugLog("🧵 Processing nop action")
368+
// loggerLessThreadSafeDebugLog("🧵 Processing nop action…")
358369
assertionFailure("nop action while being locked w/ action in thread")
359370

360371
case .endThread:
361-
// loggerLessThreadSafeDebugLog("🧵 Processing endThread action")
372+
// loggerLessThreadSafeDebugLog("🧵 Processing endThread action…")
362373
break runLoop
363374

364375
case .block(let signal):
365-
// loggerLessThreadSafeDebugLog("🧵 Processing block action for \(signal)")
376+
// loggerLessThreadSafeDebugLog("🧵 Processing block action for \(signal)…")
366377
var sigset = signal.sigset
367378
let ret = pthread_sigmask(SIG_BLOCK, &sigset, nil /* old signals */)
368379
if ret != 0 {
369380
throw SignalHandlingError.destructiveSystemError(Errno(rawValue: ret))
370381
}
371382

372383
case .unblock(let signal):
373-
// loggerLessThreadSafeDebugLog("🧵 Processing unblock action for \(signal)")
384+
// loggerLessThreadSafeDebugLog("🧵 Processing unblock action for \(signal)…")
374385
var sigset = signal.sigset
375386
let ret = pthread_sigmask(SIG_UNBLOCK, &sigset, nil /* old signals */)
376387
if ret != 0 {
377388
throw SignalHandlingError.destructiveSystemError(Errno(rawValue: ret))
378389
}
379390

380391
case .suspend(for: let signal):
381-
// loggerLessThreadSafeDebugLog("🧵 Processing suspend action for \(signal)")
392+
// loggerLessThreadSafeDebugLog("🧵 Processing suspend action for \(signal)…")
382393
let isIgnored = try Sigaction.isSignalIgnored(signal)
383394
var sigset = sigset_t()
384395
if !isIgnored {
@@ -397,18 +408,18 @@ public enum SigactionDelayer_Block {
397408
if ret != 0 || !Signal.set(from: pendingSignals).contains(signal) {
398409
/* The signal is not pending on our thread.
399410
* Which mean it is probably pending on some other thread, forever. */
400-
// loggerLessThreadSafeDebugLog("🧵 Resending signal to manager thread \(signal)")
411+
// loggerLessThreadSafeDebugLog("🧵 Resending signal to manager thread \(signal)…")
401412
pthread_kill(pthread_self(), signal.rawValue)
402413
}
403414
if !isIgnored {
404415
/* Only suspend process if signal is not ignored or sigsuspend would not return.
405416
* I know there is a race condition. */
406-
// loggerLessThreadSafeDebugLog("🧵 Calling sigsuspend for \(signal)")
417+
// loggerLessThreadSafeDebugLog("🧵 Calling sigsuspend for \(signal)…")
407418
sigsuspend(&sigset)
408419
}
409420

410421
case .drop(let signal):
411-
// loggerLessThreadSafeDebugLog("🧵 Processing drop action for \(signal)")
422+
// loggerLessThreadSafeDebugLog("🧵 Processing drop action for \(signal)…")
412423
var sigset = sigset_t()
413424
let ret = pthread_sigmask(SIG_SETMASK, nil /* new signals */, &sigset)
414425
if ret != 0 {

‎Sources/SignalHandling/DelayedSigaction/SigactionDelayer_Unsig.swift‎

Lines changed: 26 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,7 @@ public enum SigactionDelayer_Unsig {
1515
Will force the current signal to be ignored from the sigaction PoV, and handle the signal using a `DispatchSourceSignal`.
1616

1717
This is useful to use a `DispatchSourceSignal`, because GCD will not change the sigaction when creating the source,
18-
and thus, the sigaction _will be executed_ even if a dispatch source signal is setup for the given signal.
18+
and thus, the sigaction _will be executed_ even if a dispatch source signal is setup for the given signal.
1919

2020
__Example__: If you register a dispatch source signal for the signal 15 but does not ensure signal 15 is ignored,
2121
when you receive this signal your program will stop because the default handler for this signal is to quit.
@@ -53,7 +53,10 @@ public enum SigactionDelayer_Unsig {
5353
} catch {
5454
for (signal, UnsigactionID) in ret {
5555
do {try unregisterDelayedSigactionOnQueue(UnsigactionID)}
56-
catch {SignalHandlingConfig.logger?.error("Cannot unregister delayed sigaction for in recovery handler of registerDelayedSigactions. The signal will stay blocked, probably forever.", metadata: ["signal": "\(signal)"])}
56+
catch {SignalHandlingConfig.logger?.error(
57+
"Cannot unregister delayed sigaction for in recovery handler of registerDelayedSigactions. The signal will stay blocked, probably forever.",
58+
metadata: ["signal": "\(signal)", "error": "\(error)"]
59+
)}
5760
}
5861
throw error
5962
}
@@ -201,7 +204,7 @@ public enum SigactionDelayer_Unsig {
201204
* We update our original sigaction to the new sigaction.
202205
* Clients should not do that though. */
203206
unsigactionedSignal.originalSigaction = oldSigaction
204-
SignalHandlingConfig.logger?.warning("sigaction handler modified for an unsigactioned signal; the sigaction has been reset to ignore", metadata: ["signal": "\(signal)"])
207+
SignalHandlingConfig.logger?.warning("sigaction handler modified for an unsigactioned signal; the sigaction has been reset to ignore.", metadata: ["signal": "\(signal)"])
205208
}
206209
} else {
207210
let dispatchSourceSignal = DispatchSource.makeSignalSource(signal: signal.rawValue, queue: signalProcessingQueue)
@@ -225,15 +228,15 @@ public enum SigactionDelayer_Unsig {
225228
guard var unsigactionedSignal = unsigactionedSignals[id.signal] else {
226229
/* We trust our source not to have an internal logic error.
227230
* If the unsigactioned signal is not found, it is because the callee called release twice on the same unsigaction ID. */
228-
SignalHandlingConfig.logger?.error("Overrelease of unsigation", metadata: ["signal": "\(id.signal)"])
231+
SignalHandlingConfig.logger?.error("Overrelease of unsigation.", metadata: ["signal": "\(id.signal)"])
229232
return
230233
}
231234
assert(!unsigactionedSignal.handlers.isEmpty, "INTERNAL ERROR: unsigactionInfo should never be empty because when it is, the whole unsigactioned signal should be removed.")
232235

233236
guard unsigactionedSignal.handlers.removeValue(forKey: id) != nil else {
234237
/* Same here.
235238
* If the unsigaction ID was not in the unsigactionInfo, it can only be because the callee called release twice on the same ID. */
236-
SignalHandlingConfig.logger?.error("Overrelease of unsigation for signal: \(id.signal)")
239+
SignalHandlingConfig.logger?.error("Overrelease of unsigation for signal", metadata: ["signal": "\(id.signal)"])
237240
return
238241
}
239242

@@ -256,14 +259,14 @@ public enum SigactionDelayer_Unsig {
256259

257260
/** Must always be called on the `signalProcessingQueue`. */
258261
private static func processSignalsOnQueue(signal: Signal, count: UInt) {
259-
SignalHandlingConfig.logger?.debug("Processing signals, called from libdispatch", metadata: ["signal": "\(signal)", "count": "\(count)"])
262+
SignalHandlingConfig.logger?.debug("Processing signals, called from libdispatch.", metadata: ["signal": "\(signal)", "count": "\(count)"])
260263

261264
/* Get the original sigaction for the given signal. */
262265
guard let unsigactionedSignal = unsigactionedSignals[signal] else {
263266
SignalHandlingConfig.logger?.error("INTERNAL ERROR: nil unsigactioned signal.", metadata: ["signal": "\(signal)"])
264267
return
265268
}
266-
SignalHandlingConfig.logger?.trace("Original sigaction: \(unsigactionedSignal.originalSigaction)", metadata: ["signal": "\(signal)"])
269+
SignalHandlingConfig.logger?.trace("", metadata: ["signal": "\(signal)", "original-sigaction": "\(unsigactionedSignal.originalSigaction)"])
267270

268271
for _ in 0..<count {
269272
let group = DispatchGroup()
@@ -277,13 +280,11 @@ public enum SigactionDelayer_Unsig {
277280
}
278281
group.wait()
279282
if runOriginalHandlerFinal {
280-
SignalHandlingConfig.logger?.trace("Resending signal", metadata: ["signal": "\(signal)"])
281-
do {try executeOnThread(.send(signal, with: unsigactionedSignal.originalSigaction))}
282-
catch {
283-
SignalHandlingConfig.logger?.error("Error while resending signal in thread: \(error)", metadata: ["signal": "\(signal)"])
284-
}
283+
SignalHandlingConfig.logger?.trace("Resending signal.", metadata: ["signal": "\(signal)"])
284+
do {try executeOnThread(.send(signal, with: unsigactionedSignal.originalSigaction))}
285+
catch {SignalHandlingConfig.logger?.error("Error while resending signal in thread.", metadata: ["signal": "\(signal)", "error": "\(error)"])}
285286
} else {
286-
SignalHandlingConfig.logger?.trace("Signal resend skipped", metadata: ["signal": "\(signal)"])
287+
SignalHandlingConfig.logger?.trace("Signal resend skipped.", metadata: ["signal": "\(signal)"])
287288
}
288289
}
289290
}
@@ -321,7 +322,7 @@ public enum SigactionDelayer_Unsig {
321322
var emptyMask = Signal.emptySigset
322323

323324
runLoop: repeat {
324-
// loggerLessThreadSafeDebugLog("🧵 New unsigactioned signals thread loop")
325+
// loggerLessThreadSafeDebugLog("🧵 New unsigactioned signals thread loop…")
325326

326327
#if !os(Linux)
327328
ThreadSync.lock.lock(whenCondition: ThreadSync.actionInThread.rawValue)
@@ -343,15 +344,15 @@ public enum SigactionDelayer_Unsig {
343344
switch ThreadSync.action {
344345
case .nop:
345346
(/*nop*/)
346-
// loggerLessThreadSafeDebugLog("🧵 Processing nop action")
347-
assertionFailure("nop action while being locked w/ action in thread")
347+
// loggerLessThreadSafeDebugLog("🧵 Processing nop action…")
348+
assertionFailure("nop action while being locked w/ action in thread.")
348349

349350
case .endThread:
350-
// loggerLessThreadSafeDebugLog("🧵 Processing endThread action")
351+
// loggerLessThreadSafeDebugLog("🧵 Processing endThread action…")
351352
break runLoop
352353

353354
case .send(let signal, with: let sigaction):
354-
// loggerLessThreadSafeDebugLog("🧵 Processing send signal for \(signal) with \(sigaction)")
355+
// loggerLessThreadSafeDebugLog("🧵 Processing send signal for \(signal) with \(sigaction)…")
355356
/* Install the original sigaction temporarily.
356357
* In case of failure we do not even send the signal to ourselves, it’d be useless. */
357358
let previousSigaction = try sigaction.install(on: signal, revertIfIgnored: false, updateUnsigRegistrations: false)
@@ -375,12 +376,16 @@ public enum SigactionDelayer_Unsig {
375376
// let killResult = raise(signal.rawValue)
376377
let killResult = pthread_kill(thread, signal.rawValue)
377378
if killResult != 0 {
378-
completionResult.errorLogs.append(("Cannot send signal to unsigactioned thread", ["signal": "\(signal)"]))
379+
completionResult.errorLogs.append(("Cannot send signal to unsigactioned thread.", ["signal": "\(signal)", "kill_result": "\(killResult)"]))
379380
}
380381

381382
/* Re-unblock all signals (in case a handler blocked one). */
382-
if pthread_sigmask(SIG_SETMASK, &emptyMask, nil) != 0 {
383-
completionResult.errorLogs.append(("Cannot set sigmask of thread for signal resend to empty mask. The signal resending might dead-lock. Signal will still be received by your custom dispatch handler, but the original sigaction might not be delayed or called at all.", ["signal": "\(signal)"]))
383+
let sigmaskResult = pthread_sigmask(SIG_SETMASK, &emptyMask, nil)
384+
if sigmaskResult != 0 {
385+
completionResult.errorLogs.append((
386+
"Cannot set sigmask of thread for signal resend to empty mask. The signal resending might dead-lock. Signal will still be received by your custom dispatch handler, but the original sigaction might not be delayed or called at all.",
387+
["signal": "\(signal)", "sigmask_result": "\(sigmaskResult)"]
388+
))
384389
}
385390

386391
/* Race condition!

0 commit comments

Comments
 (0)