Adapter-specific tracing interferes with regular tracing output

[callumfare]

When tracing is enabled via sycl using the SYCL_UR_TRACE environment variable, some adapters also enable tracing of internal UR calls (see here).

Regular UR tracing works by printing the function call (--->urDeviceFoo) before calling into the adapter, and the arguments after the adapter returns ((ur_device_handle_t hFoo, int Bar) -> UR_RESULT_SUCCESS). When the UR adapter also prints, it becomes interleaved in this output, making it hard to read and test against.

This was ok when we still used PI tracing as PI put the function name and each argument on separate lines, but UR tracing outputs everything on a single line.

This has resulted in some SYCL E2E requiring awkward rewrites or bypassing adapter tracing altogether, e.g. intel/llvm#15167

Possible fixes include:

• Update ur_print.hpp to print over multiple lines like PI did
• Don't enable adapter-specific printing by default (has the downside of internal UR calls being invisible)
• Add an option to suppress adapter-specific printing for some E2E tests to use

[kbenzie]

Don't enable adapter-specific printing by default (has the downside of internal UR calls being invisible)

This touches on another issue @nrspruit noticed, there are also hidden UR calls in the validation layer which don't get picked up by tracing.

[pbalcer]

Don't enable adapter-specific printing by default (has the downside of internal UR calls being invisible)

This touches on another issue @nrspruit noticed, there are also hidden UR calls in the validation layer which don't get picked up by tracing.

I think this will be resolved by #2028

[pbalcer]

I never liked how PI interleaved the output of these operations.

If this is within the scope of a single logger instance, we might also consider adding call nesting/indent option to the logger, like ltrace --indent option.
This way, the output could be something like this:

urEnqueueKernel(...)
    zeCommandListAppendLaunchKernel() -> ZE_SUCCESS;
    ...
-> UR_SUCCESS

[lslusarczyk]

I noticed that regular UR tracing writes logs to stdout while adapter writes to stderr.
These can be interleaved in any way without our control therefore I want to unify by changing regular UR tracing to write to stderr too.
@pbalcer , @callumfare , @kbenzie , do you have objections on this proposed change?

[pbalcer]

By default, logger outputs to stderr: https://github.com/oneapi-src/unified-runtime/blob/main/source/common/logger/ur_logger.hpp#L134 if not configured differently.

SYCL_UR_TRACE may be setting output to stdout to preserve backward compatibility. I imagine there might be scripts that assume that the output is printed to stdout.

In general, libraries should print logs to stderr.

[kbenzie]

I'm fine with unifying on outputting to stderr in principle. It's a good point about backwards compatibility, will need to check how SYCL_PI_TRACE was behaving before it was removed.