Getting CommissionReport error level message when order is partially filled.

[ashpriom]

https://github.com/erdewit/ib_insync/blob/master/ib_insync/wrapper.py: (line 412)

... else: self._logger.error( f'commissionReport: No execution found for {commissionReport}')

Is it necessary to use error level if an order is not filled? I believe info or warning level is sufficient. It's just that I don't want to get errors when it's not really an error.

Thanks

[erdewit]

For every commission report that gets sent the corresponding fill should be already known. If that is not the case it's definitely an error. If you know how to reproduce it please let me know.

[ashpriom]

Hi @erdewit, thanks for your reply.

In my case here are the steps:

1. Place an order
2. Get the order ID from placement result returned by IB
3. Retreive all trades in interval
4. Match with the order ID
5. If filled or any other completion status, save the result
6. If not filled repeat steps 3-5 after 10 seconds

While I am waiting to grap the completion status, right before the order is completely filled (between steps 3-5) I receive the following message:

qa_ib-client.1.9mdrx48jahv0@ip-172-31-42-204.ec2.internal | {'datetime' : '2019-06-18 14:48:02,151', 'thread': 'MainThread', **'logger': 'ib_insync.wrapper', 'module': 'wrapper', 'method': 'commissionReport', 'level': 'ERROR', 'message': 'commissionReport: No execution found for CommissionReport(execId='0000e0d5.5d08dc8f.01.01', commission=1.0, currency='USD')'}**

I am not requesting any commission report, but still getting this message while getting completion status for an order. Any help would be great. Thanks.

def place_ib_order(processID, mlOrder):
    try:
        logger.debug(f'Placing order {mlOrder}')

        orderPlacementResult = []

        # Get contract details from DB for the current order ticker
        qualifiedContract = contracts.build_qualified_contract(mlOrder['ticker'])

        ibOrder = Order()
        ibOrder.action = mlOrder['position']
        ibOrder.orderType = CONFIG['ib']['ordertype']
        ibOrder.account = os.environ.get("IB_ACCOUNT")
        ibOrder.totalQuantity = mlOrder['number_of_shares']

        trade = ib.placeOrder(*qualifiedContract, ibOrder)

        order_placement_result_json = ujson.dumps(
            {
                'ticker': trade.contract.symbol,
                'action': trade.order.action,
                'totalQuantity': trade.order.totalQuantity,
                'trade' : trade
            }, ensure_ascii=False).replace("'", "")

        orderPlacementResult.append((
            processID,
            trade.order.orderId,
            trade.log[0].time.strftime("%Y-%m-%d %H:%M:%S"),
            order_placement_result_json,
            trade.orderStatus.status
        ))

        return orderPlacementResult

    except Exception as e:
        logger.exception(str(e))

def get_ib_order_status(processID, orderPlacementResult):
    try:
        orderExecutionTuple = []

        orderProcessed = False
        orderPlacementResultTuple = orderPlacementResult[0]
        orderID = orderPlacementResultTuple[1]
        orderPlacementData = ujson.loads(orderPlacementResultTuple[3])

        logger.debug(f'Getting completed status of order {orderID}')

        while orderProcessed is False:

            logger.debug(f'Recieving updated trades from IB')
            ib.waitOnUpdate()

            allTrades = ib.trades()

            for trade in allTrades:

                if trade.order.orderId == orderID:

                    logger.debug(f'Order ID:{trade.order.orderId}  Status: {trade.orderStatus.status}  Filled:{trade.filled()}  Remaining:{trade.remaining()}')

                    if trade.orderStatus.status in ['Filled', 'Cancelled', 'ApiCancelled', 'Inactive']: # Order success path
                        order_result_json = ujson.dumps(
                            {
                                'ticker': orderPlacementData['ticker'],
                                'action': orderPlacementData['action'],
                                'totalQuantity': orderPlacementData['totalQuantity'],
                                'trade': trade
                            }, ensure_ascii=False).replace("'", "")

                        orderExecutionTuple.append((
                            processID,
                            trade.order.orderId,
                            trade.log[0].time.strftime("%Y-%m-%d %H:%M:%S"),
                            order_result_json,
                            trade.orderStatus.status
                        ))

                        orderProcessed = True
                        break # no need to continue iterating allTrades because completed status has been captured

            if orderProcessed:
                break # exit the while loop for current order ID and continue with next order
            else:
                ib.sleep(5) # Wait before requesting trade update from IB

        logger.debug(f'Order {orderID} finished execution. Status: {trade.orderStatus.status}')
        return orderExecutionTuple[0]

    except Exception as e:
        logger.exception(str(e))

[erdewit]

I can reproduce the issue with multiple connected clients. A client that did not initiate the trade still gets the commission reports but IB does not send it the fills. This 'other' client can't then match the report with its fill.

I've modified the code to ignore the reports in other clients, so that it is not logged as an error any more.

[ashpriom]

Thanks a lot @erdewit :) Yes I do have multiple clients connected and it makes sense now. When do you plan to release this change so that I can update the package?