ConsoleSpanExporter doesn't print out as expected

[codeboten]

Environment

I setup a new virtualenv and ran through the http example: https://github.com/open-telemetry/opentelemetry-python/tree/master/examples/http.

Expected

After running the client, I was expecting to see the span being printed in both the client and the server consoles.

Actual

The span was printed to the client console. On the server side, the span was only printed once I exited the application (ctrl+c)

[c24t]

That's because of the BatchExportSpanProcessor, it only exports every 60 seconds or immediately on exit. The client prints because it exits, but you'd see the same thing with e.g. a sleep at the end.

This is confusing behavior for an example though.

[codeboten]

I just tested this again with the batch processor, waited over 2 minutes and still nothing until I cancelled the server process. I haven't tested this with other exporters to test the behaviour. I agree the example should probably be changed to use the SImple processor, but I think there is still a regression somewhere in the ConsoleSpanExporter

[ocelotl]

I just tested this again with the batch processor, waited over 2 minutes and still nothing until I cancelled the server process. I haven't tested this with other exporters to test the behaviour. I agree the example should probably be changed to use the SImple processor, but I think there is still a regression somewhere in the ConsoleSpanExporter

Yes, I also think there is a regression. This is happening with the auto instrumentation example too, it didn't happen before.

[knabben]

Looks like the flush of the buffering never happens, maybe it makes sense to call self.out.flush() at the end of ConsoleSpanExporter.export.

[mauriciovasquezbernal]

@knabben yes, you are right. I am already preparing a patch for this issue.

[mauriciovasquezbernal]

exports every 60 seconds

Actually the default delay is 5 seconds

opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/trace/export/__init__.py

Line 107 in 5b2e693

schedule_delay_millis: float = 5000,

I am proposing a fix for this on #455.