error: a C finalizer called back into Haskell.

NorfairKing commented 3 years ago

Moving from #71 :

I'm still seeing this message:

   XXXXXXXXXXXXXXXXXX: error: a C finalizer called back into Haskell.
   This was previously allowed, but is disallowed in GHC 6.10.2 and later.
   To create finalizers that may call back into Haskell, use
   Foreign.Concurrent.newForeignPtr instead of Foreign.newForeignPtr.

It looks like setting a log callback that does logging is not supported, which would be strange.

CC @llattila

AlexeyRaga commented 3 years ago

It is strange indeed. Somewhere we don't dispose of something. Perhaps digging into logging callbacks in librdkafka is required :(

phile314 commented 3 years ago

We have seen the same problem, but in our case it seems to be related to the error callback. Here it happens when the application is shutting down. GDB trace:

tiko-thriftproxy-test: error: a C finalizer called back into Haskell.
   This was previously allowed, but is disallowed in GHC 6.10.2 and later.
   To create finalizers that may call back into Haskell, use
   Foreign.Concurrent.newForeignPtr instead of Foreign.newForeignPtr.

Thread 1 "tiko-thriftprox" hit Breakpoint 1, stg_exit (n=n@entry=1) at rts/RtsStartup.c:613
613 rts/RtsStartup.c: No such file or directory.
(gdb) backtrace
#0  stg_exit (n=n@entry=1) at rts/RtsStartup.c:613
#1  0x00000000015171ea in rts_lock () at rts/RtsAPI.c:593
#2  0x000000000127ff21 in zdhwzmkafkazmclientzm4zi0zi1zmDGjnzzG7Ebkp8iOJOEOSfgBzdKafkaziInternalziRdKafkazdhwzzmkafkazzmclientzzm4zzi0zzi1zzmDGjnzzzzG7Ebkp8iOJOEOSfgBzuKafkazziInternalzziRdKafkazumkErrorCallback ()
#3  0x00007ffff5c17d90 in rd_kafka_poll_cb (rk=rk@entry=0x1994d80, rkq=rkq@entry=0x19c6dc0, rko=rko@entry=0x7fff38001ef0, cb_type=cb_type@entry=RD_KAFKA_Q_CB_RETURN, opaque=opaque@entry=0x0) at rdkafka.c:3424
#4  0x00007ffff5c1876b in rd_kafka_consumer_close (rk=rk@entry=0x1994d80) at rdkafka.c:2915
#5  0x00007ffff5c217a3 in rd_kafka_destroy_app (rk=0x1994d80, flags=flags@entry=0) at rdkafka.c:968
#6  0x00007ffff5c21cac in rd_kafka_destroy (rk=<optimized out>) at rdkafka.c:1014
#7  0x000000000153fc73 in runCFinalizers (list=<optimized out>) at rts/Weak.c:31
#8  0x000000000153fd74 in scheduleFinalizers (cap=cap@entry=0x1907e50, list=0x42005ebd08) at rts/Weak.c:105
#9  0x0000000001525899 in GarbageCollect (collect_gen=collect_gen@entry=1, do_heap_census=do_heap_census@entry=false, gc_type=gc_type@entry=1, cap=0x1907e50, cap@entry=0x197cce0, idle_cap=idle_cap@entry=0x19c6c20) at rts/sm/GC.c:729
#10 0x000000000151cf84 in scheduleDoGC (pcap=pcap@entry=0x7ffffffece28, task=task@entry=0x198d200, force_major=force_major@entry=true) at rts/Schedule.c:1807
#11 0x000000000040bc54 in exitScheduler (wait_foreign=wait_foreign@entry=false) at rts/Schedule.c:2666
#12 0x000000000151f439 in hs_exit_ (wait_foreign=false) at rts/RtsStartup.c:387
#13 hs_exit_ (wait_foreign=false) at rts/RtsStartup.c:355
#14 0x000000000151f925 in shutdownHaskellAndExit (n=0, fastExit=fastExit@entry=0) at rts/RtsStartup.c:545
#15 0x0000000001516c77 in hs_main (argc=<optimized out>, argv=<optimized out>, main_closure=0x1765d60, rts_config=...) at rts/RtsMain.c:99
#16 0x000000000040c0d2 in main ()

rdkafka library:

ldd result/bin/tiko-thriftproxy-test 
        ....
    librdkafka.so.1 => /nix/store/76mrajidxq2jlrdn8qbcrgy1j1j09d74-rdkafka-1.3.0/lib/librdkafka.so.1 (0x00007f6f705a8000)
        ....

phile314 commented 3 years ago

There is also this comment in the code, which seems to imply that rd_kafka_close_consumer should not be called, but according to the stack trace above rdKafkaDestroy calls that implicitly anyway.

  newRdKafkaT :: RdKafkaTypeT -> RdKafkaConfTPtr -> IO (Either Text RdKafkaTPtr)
  newRdKafkaT kafkaType confPtr =
      allocaBytes nErrorBytes $ \charPtr -> do
          duper <- rdKafkaConfDup confPtr
          ret <- rdKafkaNew kafkaType duper charPtr (fromIntegral nErrorBytes)
          withForeignPtr ret $ \realPtr -> do
              if realPtr == nullPtr then peekCText charPtr >>= return . Left
              else do
                  -- do not call 'rd_kafka_close_consumer' on destroying all Kafka.
                  -- when needed, applications should do it explicitly.
                  -- {# call rd_kafka_destroy_flags #} realPtr 0x8
                  addForeignPtrFinalizer rdKafkaDestroy ret
                  return $ Right ret

Maybe the flag RD_KAFKA_DESTROY_F_NO_CONSUMER_CLOSE should be set?

AlexeyRaga commented 3 years ago

I don't really know :( Further investigation is needed...

phile314 commented 3 years ago

https://github.com/haskell-works/hw-kafka-client/pull/169

AlexeyRaga commented 3 years ago

Should be fixed by #169

haskell-works / hw-kafka-client

error: a C finalizer called back into Haskell. #151